-
Notifications
You must be signed in to change notification settings - Fork 11
fix: only flush traces that no other task is still building #634
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from all commits
bc4ad7d
d426a0b
7bcc29c
ef357fe
db67cfa
9cca439
a21106f
3ffce80
a7bbdef
cbdd070
02cff04
1f93c00
a3fb9f9
d22439e
53e5f7e
10405f1
033969b
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change | ||||||||||||||||||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
|
@@ -633,6 +633,10 @@ def _safe_prepare_call( | |||||||||||||||||||||||||||||||||
| bool | ||||||||||||||||||||||||||||||||||
| True if preparation succeeded, False if it failed | ||||||||||||||||||||||||||||||||||
| """ | ||||||||||||||||||||||||||||||||||
| # Captured before the attempt, not read in the handler below: an enclosing decorated call's | ||||||||||||||||||||||||||||||||||
| # span means the trace being built is that call's, not this one's, and the answer must not | ||||||||||||||||||||||||||||||||||
| # depend on how far `_prepare_call` got before raising. | ||||||||||||||||||||||||||||||||||
| outermost = not _get_or_init_list(_span_stack_context) | ||||||||||||||||||||||||||||||||||
| try: | ||||||||||||||||||||||||||||||||||
| self._prepare_call(span_type, span_params, dataset_record) | ||||||||||||||||||||||||||||||||||
| return True | ||||||||||||||||||||||||||||||||||
|
|
@@ -641,8 +645,30 @@ def _safe_prepare_call( | |||||||||||||||||||||||||||||||||
| _logger.error("Galileo logging initialization failed: %s", e, exc_info=True) | ||||||||||||||||||||||||||||||||||
| else: | ||||||||||||||||||||||||||||||||||
| _logger.warning("Galileo logging initialization failed, continuing without logging: %s", e) | ||||||||||||||||||||||||||||||||||
| # Preparation may already have started a trace, and returning False means the caller | ||||||||||||||||||||||||||||||||||
| # skips _finalize_call - so nothing else would ever report this context as done with | ||||||||||||||||||||||||||||||||||
| # it, leaving it held back from every flush. This context is not building it. | ||||||||||||||||||||||||||||||||||
| # | ||||||||||||||||||||||||||||||||||
| # Only when this call was the outermost one, though: an enclosing call is still building | ||||||||||||||||||||||||||||||||||
| # the trace, and releasing it on that call's behalf would expose it to a sibling's flush | ||||||||||||||||||||||||||||||||||
| # mid-build. That call reports its own hand-off when it returns. | ||||||||||||||||||||||||||||||||||
| if outermost: | ||||||||||||||||||||||||||||||||||
| self._release_trace_being_built() | ||||||||||||||||||||||||||||||||||
| return False | ||||||||||||||||||||||||||||||||||
|
fercor-cisco marked this conversation as resolved.
Comment on lines
+648
to
657
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🟡 minor (bug): Same family as the generator guard above: this release is unconditional, so when a nested Confirmed with a probe that makes only the nested call's The reachability is narrower than the generator case — most raisers inside
Suggested change
🤖 Generated by the Astra agent
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Confirmed and fixed in Reproduced with a depth-aware Deviation from your fix, and I think it is strictly better. You suggested reading the stack inside the outermost = not _get_or_init_list(_span_stack_context)
try:
self._prepare_call(...)
except Exception:
...
if outermost:
self._release_trace_being_built()Same cost. Release-site audit, since your comment asks about scope. All ten On reachability, you were right to hedge and I will go further. Every logger call Four tests, four distinct mutations, all verified separately. The first two are complementary and both
The new test also failed pre-fix with Your R5 remedy needed one correction on the third test. The
|
||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| def _release_trace_being_built(self) -> None: | ||||||||||||||||||||||||||||||||||
| """Report that this context is no longer building the trace it had started, if any.""" | ||||||||||||||||||||||||||||||||||
| try: | ||||||||||||||||||||||||||||||||||
| logger = self.get_logger_instance() | ||||||||||||||||||||||||||||||||||
| trace_id = logger._current_trace_id() | ||||||||||||||||||||||||||||||||||
| if trace_id is not None: | ||||||||||||||||||||||||||||||||||
| logger._mark_trace_finished(trace_id) | ||||||||||||||||||||||||||||||||||
| except Exception as e: | ||||||||||||||||||||||||||||||||||
| # Debug, not a warning: the most likely raiser is `get_logger_instance()` above, and the | ||||||||||||||||||||||||||||||||||
| # caller that could not build a logger has already reported that failure. There is no | ||||||||||||||||||||||||||||||||||
| # trace to release in that case, so a second message per decorated call is pure noise. | ||||||||||||||||||||||||||||||||||
| _logger.debug("Could not release the trace being built: %s", e) | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| def _prepare_call( | ||||||||||||||||||||||||||||||||||
| self, span_type: SPAN_TYPE | None, span_params: dict[str, Any], dataset_record: DatasetRecord | None | ||||||||||||||||||||||||||||||||||
| ) -> None: | ||||||||||||||||||||||||||||||||||
|
|
@@ -698,6 +724,19 @@ def _prepare_call( | |||||||||||||||||||||||||||||||||
| span = client_instance.add_workflow_span(input=input_, name=name, created_at=created_at) | ||||||||||||||||||||||||||||||||||
| _get_or_init_list(_span_stack_context).append(span) | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| # This context owns the trace until the outermost decorated call returns, which is what | ||||||||||||||||||||||||||||||||||
| # _finalize_call reports. Concurrent tasks share one logger and one trace list, so a | ||||||||||||||||||||||||||||||||||
| # sibling's flush must not carry the trace away while spans are still being added to it. | ||||||||||||||||||||||||||||||||||
| # Re-marked on every entry because a reused trace was released by the previous call. | ||||||||||||||||||||||||||||||||||
| # | ||||||||||||||||||||||||||||||||||
| # Deliberately the last statement: the caller skips _finalize_call when _prepare_call | ||||||||||||||||||||||||||||||||||
| # raises, so marking any earlier would strand the trace - held back from every flush with | ||||||||||||||||||||||||||||||||||
| # nothing left to release it. Nothing above yields, so the trace cannot be observed by | ||||||||||||||||||||||||||||||||||
| # another task before this runs. | ||||||||||||||||||||||||||||||||||
| trace_being_built = _trace_context.get() | ||||||||||||||||||||||||||||||||||
| if trace_being_built is not None: | ||||||||||||||||||||||||||||||||||
| client_instance._mark_trace_unfinished(trace_being_built.id) | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| def _get_input_from_func_args( | ||||||||||||||||||||||||||||||||||
| self, *, is_method: bool = False, func_args: tuple = (), func_kwargs: dict | None = None | ||||||||||||||||||||||||||||||||||
| ) -> Any: | ||||||||||||||||||||||||||||||||||
|
|
@@ -748,9 +787,23 @@ def _finalize_call( | |||||||||||||||||||||||||||||||||
| ------- | ||||||||||||||||||||||||||||||||||
| The original result, possibly wrapped if it's a generator | ||||||||||||||||||||||||||||||||||
| """ | ||||||||||||||||||||||||||||||||||
| if inspect.isgenerator(result): | ||||||||||||||||||||||||||||||||||
| return self._wrap_sync_generator_result(span_type, span_params, result) | ||||||||||||||||||||||||||||||||||
| if inspect.isasyncgen(result): | ||||||||||||||||||||||||||||||||||
| if inspect.isgenerator(result) or inspect.isasyncgen(result): | ||||||||||||||||||||||||||||||||||
| # The wrappers below report the hand-off from `_handle_call_result` when the generator | ||||||||||||||||||||||||||||||||||
| # is exhausted, but only `_async_log` keeps the wrapper it is handed: `_sync_log` | ||||||||||||||||||||||||||||||||||
| # discards it and returns the raw generator, and both generator kinds route through | ||||||||||||||||||||||||||||||||||
| # `_sync_log` (`asyncio.iscoroutinefunction` is False for an async generator function). | ||||||||||||||||||||||||||||||||||
| # So on that path nothing would ever release the trace. Reported here instead, where | ||||||||||||||||||||||||||||||||||
| # both paths pass. The stack still holds this call's own span - only | ||||||||||||||||||||||||||||||||||
| # `_handle_call_result` pops it - so the outermost call is the one that leaves it alone. | ||||||||||||||||||||||||||||||||||
| # Only a workflow, agent or untyped call pushed a span in `_prepare_call`: a | ||||||||||||||||||||||||||||||||||
| # non-concludable span type pushed nothing, so for it a stack of one holds an enclosing | ||||||||||||||||||||||||||||||||||
| # call's span, and reporting the hand-off would release a trace that call is still | ||||||||||||||||||||||||||||||||||
| # building. | ||||||||||||||||||||||||||||||||||
| pushed_own_span = not span_type or is_concludable_span_type(span_type) | ||||||||||||||||||||||||||||||||||
| if len(_get_or_init_list(_span_stack_context)) <= (1 if pushed_own_span else 0): | ||||||||||||||||||||||||||||||||||
| self._release_trace_being_built() | ||||||||||||||||||||||||||||||||||
|
fercor-cisco marked this conversation as resolved.
|
||||||||||||||||||||||||||||||||||
| if inspect.isgenerator(result): | ||||||||||||||||||||||||||||||||||
| return self._wrap_sync_generator_result(span_type, span_params, result) | ||||||||||||||||||||||||||||||||||
| return self._wrap_async_generator_result(span_type, span_params, result) | ||||||||||||||||||||||||||||||||||
| return self._handle_call_result(span_type, span_params, result) | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
|
|
@@ -905,6 +958,14 @@ def _handle_call_result(self, span_type: SPAN_TYPE | None, span_params: dict[str | |||||||||||||||||||||||||||||||||
| except Exception as e: | ||||||||||||||||||||||||||||||||||
| _logger.error(f"Failed to create trace for span '{span_name}' (type: {span_type}): {e}", exc_info=True) | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| # The outermost decorated call has returned, so this context has stopped adding to the | ||||||||||||||||||||||||||||||||||
| # trace and any flush may now send it. The trace itself is deliberately left open for a | ||||||||||||||||||||||||||||||||||
| # later decorated call in this context to reuse, so concluding is not the signal here. | ||||||||||||||||||||||||||||||||||
| if not _get_or_init_list(_span_stack_context): | ||||||||||||||||||||||||||||||||||
| trace = _trace_context.get() | ||||||||||||||||||||||||||||||||||
| if trace is not None: | ||||||||||||||||||||||||||||||||||
| logger._mark_trace_finished(trace.id) | ||||||||||||||||||||||||||||||||||
|
fercor-cisco marked this conversation as resolved.
|
||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| return result | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| def _wrap_sync_generator_result( | ||||||||||||||||||||||||||||||||||
|
|
@@ -1092,7 +1153,14 @@ def flush( | |||||||||||||||||||||||||||||||||
| on_error: Callable[[Exception], None] | None = None, | ||||||||||||||||||||||||||||||||||
| ) -> None: | ||||||||||||||||||||||||||||||||||
| """ | ||||||||||||||||||||||||||||||||||
| Upload all captured traces under a project and log stream context to Galileo. | ||||||||||||||||||||||||||||||||||
| Upload traces captured under a project and log stream context to Galileo. | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| Uploads the trace the calling code is building, plus every trace that no live task or thread is | ||||||||||||||||||||||||||||||||||
| still building. A trace another context is part-way through building stays queued and leaves with | ||||||||||||||||||||||||||||||||||
| that context's own flush instead, so it is not sent without its output, spans and duration. | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| Nothing is returned and upload errors are swallowed (see ``on_error``), so a normal return is not | ||||||||||||||||||||||||||||||||||
| a confirmation that a given trace was uploaded. | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| If no project or log stream is provided, then the currently initialized context is used. | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
|
|
@@ -1147,9 +1215,11 @@ def _on_flush_error(exc: Exception) -> None: | |||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| def flush_all(self) -> None: | ||||||||||||||||||||||||||||||||||
| """ | ||||||||||||||||||||||||||||||||||
| Upload all captured traces under all contexts to Galileo. | ||||||||||||||||||||||||||||||||||
| Upload traces captured under all contexts to Galileo. | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
| This method flushes all traces regardless of project or log stream. | ||||||||||||||||||||||||||||||||||
| This method flushes every cached logger regardless of project or log stream. Each one uploads the | ||||||||||||||||||||||||||||||||||
| same set as `flush()` does: the trace the calling code is building, plus every trace that no live | ||||||||||||||||||||||||||||||||||
| task or thread is still building. | ||||||||||||||||||||||||||||||||||
| """ | ||||||||||||||||||||||||||||||||||
| GalileoLoggerSingleton().flush_all() | ||||||||||||||||||||||||||||||||||
| _span_stack_context.set([]) | ||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
src/galileo/decorator.py:1142-1142(line not in diff)🟡 minor (documentation):
galileo_context.flush()is the flush most users reach for (it is the shape in SAO-15919), and its contract has changed: it now sends the caller's own trace plus traces no live context is still building, not "all captured traces".logger.flush()/async_flush()docstrings were updated for this; these were not, so the public-facing wording now overstates what happens and gives no hint why a return of[]or a partial send is expected. Same forflush_all()at line 1197 (and, less visibly,GalileoLoggerSingleton.flush()/flush_all()).🤖 Generated by the Astra agent
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Taken, in
033969b3, and the README half in10405f1b. You are right that this is the flush most usersreach for and the shape in the originating ticket, and that
cbdd0705updatedGalileoLogger.flush()/async_flush()while leaving the wrappers users actually call saying "Upload all captured traces".All four sites updated —
galileo_context.flush,galileo_context.flush_all, and bothGalileoLoggerSingletonequivalents — with the wording lifted fromlogger.py:2155-2157so the flush docsread as one voice. A repo-wide grep for the stale phrasing across
src/,tests/,README.mdandCHANGELOG.mdfound exactly these four, nothing else to chase. (Minor: the definitions are atdecorator.py:1147and:1209, not:1142/:1197.)One adaptation of your second point. You asked for "the return value is the uploaded batch rather than
the fate of your trace" — that is
GalileoLogger.flush()'s contract, but all four wrappers returnNone. So ongalileo_context.flush()it became "nothing is returned and upload errors are swallowed(see
on_error), so a normal return is not a confirmation", which is the same warning in the shape thesefunctions actually have. The README paragraph covers both wrappers explicitly, since it sits under a
galileo_context.flush()example.Contract only, no mechanism — no
_traces_being_built, owner liveness, weakrefs or thread identity.Deliberate: per-thread logger key isolation is still in play and would change how traces group, so
documenting the current mechanism would be documenting something I expect to move.
Prose-only, so the bar was "nothing executable moved":
git diff -U0inspected line by line,ruffclean,mypy12 errors both sides → 0 new,inspect.getdocon all four renders with numpydocParameterssections intact, suite unchanged at 2099 / 5.