Skip to content

fix: only flush traces that no other task is still building - #634

Open
fercor-cisco wants to merge 17 commits into
mainfrom
fernando.SAO-15919.fix
Open

fix: only flush traces that no other task is still building#634
fercor-cisco wants to merge 17 commits into
mainfrom
fernando.SAO-15919.fix

Conversation

@fercor-cisco

@fercor-cisco fercor-cisco commented Aug 15, 2026

Copy link
Copy Markdown
Contributor

User description

Summary

Concurrent tasks share one GalileoLogger, and therefore one self.traces list, whenever they run on the same thread against the same project and log stream (GalileoLoggerSingleton._get_key keys on thread + mode + project + log_stream). _flush_batch() treated that shared list as if it belonged to the caller, which produced three distinct failures:

  1. Traces silently dropped. The list was cleared unconditionally after the ingest await, so a trace appended during that await — never part of the already-frozen payload — was discarded. Its own flush() then found an empty list, took the if not self.traces early return, sent nothing, and reported success.
  2. The same trace sent repeatedly. Two overlapping flushes both took the whole list, so each trace went out once per in-flight flush.
  3. Traces sent before they were finished. A flush shipped every trace in the list, including traces a sibling task had started and not concluded — so they reached the backend with no output, no duration, no status code, and without any span added after that moment.

All three are silent: the local call succeeds and nothing raises.

The third is the most damaging, because Traces.ingest_traces calls model_dump(mode="json") synchronously before its first await. The payload is frozen at that point, so a later conclude() mutates a model that has already been serialised and cannot repair it. Fixing (1) alone makes it worse: once the batch is detached from the list, the owning task's own flush finds nothing left to send, so the half-built version is the only one that ever ships.

Duplicate sends are not harmless either. The ingest endpoint rejects a batch containing an already-seen trace id — and it rejects the whole batch, so a valid trace riding alongside a duplicate is lost with it. flush() swallows that error and returns [].

Fix 1 — hand the batch off instead of clearing afterwards

logged_traces, self.traces = ready, still_running

A trace appended mid-flush lands in the new list and is picked up by the next flush. Two effects fall out of the same change: the return value stops aliasing a list that kept growing after the payload was built, and two concurrent flushes can no longer send the same trace.

Detaching up-front would have turned a failed ingest into data loss — previously the exception skipped the clear and the traces were retried — so the batch is restored on failure, oldest first. BaseException, not Exception: asyncio.CancelledError does not derive from Exception, so a cancelled async_flush() would otherwise drop the detached batch outright. The send moved into a small _send_ingest_request() helper so the hook/client branching stays readable inside the try; no behaviour change there.

Fix 2 — a flush only sends traces nobody is still building

The logger now tracks which traces a context is still building, and _flush_batch partitions the list in one await-free pass: traces belonging to other contexts stay behind for their owners' flush.

  • The flushing caller always claims its own trace, resolved from the parent-chain ContextVar before dispatch (sync flush() hands the coroutine to a pool thread). So flushing your own open trace still sends it — unchanged behaviour — and it works even when auto-concluding that trace fails.
  • Routes that finish with a trace report it, or nothing in that context will: conclude(), reset_parent_tracking() — for the caller's own trace only — terminate(), @log finishing its outermost call, and @log returning a generator. Enumerating them is not sufficient on its own, which is what Fix 3 addresses: two of these were missing until the review found them, and before the liveness bound a missed route meant a trace held back from every flush until process exit.
  • @log needed explicit hooks. It deliberately leaves the trace open so a later decorated call in the same context can reuse it, so on that path "unconcluded" does not mean "still being built". _prepare_call marks ownership once preparation completes; _finalize_call releases it when the outermost decorated call returns; _safe_prepare_call releases it if preparation failed, since the wrappers then skip _finalize_call; and _finalize_call releases on its generator branches too, because the wrapper that would otherwise report the hand-off is discarded by _sync_log (see Fix 3).
  • The OpenAI wrapper needed the same. It starts the trace itself when there is no active one, and only APIStatusError is routed into the processing that concludes it — a connection error or timeout unwinds straight to its error path. Released there now.

Batch coalescing is unaffected: traces that are finished still leave together in one request, so this costs no extra requests and no extra clients.

Fix 3 — hold a trace back only while its owner is alive

The hold-back is bounded by the liveness of the context doing the building. _mark_trace_unfinished() records a weak reference to the owning asyncio.Task — or thread, for synchronous callers — and the partition skips a trace only while not task.done() / thread.is_alive(). For a thread owner that check is made against the thread asking for the flush, since a thread cannot be flushing and mid-build at once: without it a pool worker — which outlives the job that started the trace — held that trace for the life of the worker. Identity, not name, because anyio names every worker alike.

Unbounded, an owner that went away without concluding left a trace nothing could ever claim: the claim comes from the caller's own parent chain, and the abandoned chain died with its owner. Every flush skipped it and terminate() was the only release. That is not a safety net in a plain asyncio.run script — at interpreter exit the flush coroutine is abandoned un-awaited, so the trace was lost outright rather than shipped late. The failure mode of an unreleased mark is now a trace that ships unconcluded, not one that never ships.

Two release-site gaps found the same way are fixed directly rather than left to the bound:

  • reset_parent_tracking() released only the caller's own trace, so it did nothing for one abandoned by another context.
  • @log on a generator or async-generator function never released at all. _finalize_call wraps a generator result and returns the wrapper, but _sync_log discards that return value and hands back the raw generator, so the wrapper is never iterated and _handle_call_result — the only place the decorator reports its hand-off — never runs. Both generator kinds land there, since asyncio.iscoroutinefunction is False for an async generator function. The hand-off is reported from _finalize_call instead, guarded on len(stack) <= 1, because only _handle_call_result pops this call's own span.

An age bound and an attempt bound were the alternatives. An age bound ships a legitimately long-running trace mid-build once it crosses the threshold, which is failure (3) again, and the threshold is arbitrary; an attempt bound measures flush frequency rather than abandonment. Liveness needs no constant.

Residuals, stated rather than implied. A synchronous owner is compared by identity against the thread asking for the flush, because a thread cannot be flushing and mid-build at the same time. Without that, a pool worker — which outlives the job that started the trace — held it for the life of the worker, and the next job on that worker cannot claim it either: pools that copy the context per job, which is what anyio does and therefore what FastAPI's synchronous endpoints do, hand it an empty parent chain. An earlier version of this paragraph called that shape "no change, since it ships today via the caller's own claim". That was wrong — it is true only for ThreadPoolExecutor, which does not copy the context — and main ships that trace on the first flush.

Three cases this still does not cover:

  • A flush from a different worker still holds an abandoned trace while its owner lives. anyio names every worker "AnyIO worker thread", so they resolve to one logger and one trace list. main sent that trace on the first flush, unconcluded; here it waits for a flush on the owning worker, or for atexit.
  • An immortal owner — an asyncio.to_thread executor thread, or a user-managed long-lived worker — holds an abandoned trace against every other thread's flush until process exit, where main sent it on the first flush. atexit still ships it, unconcluded, so this is lateness rather than loss unless the process dies without running its exit handlers.
  • A trace genuinely mid-build on the flushing thread is sent mid-build. That needs a switch out of an entered context, i.e. gevent-patched threading, where current_thread() is per-greenlet — and it is what main does unconditionally, for every trace. Not reachable through generators — PEP 568 is unimplemented, so a sync generator has no context of its own and its trace stays in the flusher's parent chain, where the caller's claim ships it — nor through nested copy_context().run(...), since a Context cannot be re-entered.

And a child task that inherits an open trace through the copied context can be released early if the marking task ends first — @log re-marks on entry, so this reaches direct logger callers rather than decorator users.

Also fixed

_auto_conclude_trace() derived a trace's inherited output from self.traces[-1] — the last entry of the shared list. Under concurrency that stamped the flushing task's trace with an output computed from a sibling's spans: a wrong output rather than a missing one, and invisible in the console. It now uses the caller's own chain root, falling back to traces[-1] only where there is no open chain (distributed mode, where start_trace() resets the list to a single entry).

Who is affected

Anything that holds a trace open across an await while another task flushes. Notably plain @log on an async function plus asyncio.gather, using the ordinary blocking flush() — a decorated coroutine necessarily holds its trace open across every await inside it. In a five-task reproduction that ships two of five traces with no output before this change, and five complete traces after.

GalileoAsyncCallback with the default start_new_trace=True is not affected by failure (3): async_commit() calls start_trace(), log_node_tree() and conclude() with no await between them, so no sibling can observe an unconcluded trace on that path. It is still affected by (1) and (2), which happen inside the flush itself.

Tests

24 deterministic tests, no live server. Ordering is driven by asyncio.Event, never sleeps; each task is a real asyncio.Task so contexts are independent while the trace list stays shared — the actual shape of the defect. Only the network egress is mocked, and only to hold the await open, since in production that window is ordinary network latency.

Six demonstrate the defects and fail without the fix:

Test Failure before
test_trace_added_during_ingest_is_not_dropped ['New York'] == ['London', 'New York']
test_flush_does_not_ship_another_tasks_unconcluded_trace [['London', 'New York']] == [['New York']]
test_trace_held_open_during_a_sibling_flush_is_sent_once_with_its_output ('London', None) != ('London', 'rainy in London')
test_auto_conclude_does_not_borrow_another_tasks_output New York's trace concluded with London's answer
test_failed_flush_keeps_holding_back_another_tasks_trace the retry adopted the sibling's open trace
test_concurrent_decorated_coroutines_do_not_flush_each_others_traces ('london_forecast', None) swept into another task's flush

Four more pin the bound in Fix 3. These fail on the earlier commits of this branch, where the hold-back was unbounded — not on main, which has no hold-back to bound:

Test Failure without the bound
test_flush_sends_a_trace_whose_owning_task_has_finished [] == [['London']] — the abandoned trace never left
test_reset_parent_tracking_in_another_context_does_not_strand_a_trace the same, after reset_parent_tracking() in the flushing context
test_decorated_generator_releases_its_trace_when_the_call_returns [] == [['stream_forecast']]
test_decorated_async_generator_releases_its_trace_when_the_call_returns [] == [['stream_forecast_async']]

The two decorator tests keep the owning task alive on purpose, so liveness alone cannot ship the trace and they pin the decorator hand-off rather than the bound.

Two more pin the thread rule, and are red on the commit before it:

Test Failure without the rule
test_flush_sends_a_trace_abandoned_on_a_still_alive_pool_thread [] == [['London']] — held for the life of the worker
test_flush_holds_back_a_trace_another_live_thread_is_building [['London']] == [] — comparing thread names, or dropping the thread check, ships a live owner's half-built trace

The first runs two copy_context() jobs on one thread, because that isolation is the property that matters rather than the pool library: ThreadPoolExecutor does not copy the context, so its second job claims the trace and the shape never reproduced there. It drives the public flush(), so it also fails if the thread is read inside _flush_batch — which runs on an EventLoopThreadPool thread — rather than captured before dispatch.

The rest pin behaviour this change could plausibly break — the caller's own open trace still ships, terminate() still sends a trace whose owner never concluded it, reset_parent_tracking() does not strand its trace, a reused trace is protected while a second decorated call builds it, a trace is not stranded when span setup or an OpenAI call fails, failure and cancellation still restore the batch, and coalescing still batches.

Each of those was checked by removing the code it protects and confirming the test fails. That found two tests which looked like guards but asserted nothing load-bearing, and two real bugs in the first version of this change.

Test plan

  • Six tests fail on main, pass with this change
  • Four tests fail on the unbounded-hold-back commits of this branch, pass with Fix 3; each new test also fails when only the code it guards is removed, and the three original hold-back tests fail if the hold-back is disabled entirely
  • Full suite: 2095 passed, 5 skipped; stable across repeat runs under xdist with random ordering
  • ruff check / ruff format --check clean on changed files
  • mypy unchanged: 34 errors across the three changed source files on main and on this branch, 0 new
  • Five-task reproduction: 10 trace-sends with 5 duplicates and 2 missing outputs before, 5 sends and 0 of either after — invariant across a simulated-latency sweep from 2 ms to 800 ms
  • Sequential single-task usage byte-identical to before this change
  • @log + asyncio.gather reproduction: 2 of 5 traces output-less before, 0 after
  • Traces from tasks that finish without flushing still leave at galileo_context.__exit__, matching previous behaviour
  • GalileoAsyncCallback driven concurrently, both start_new_trace settings: identical before and after
  • Verified against a local API server that the two-task drop reproduction drops a trace on every run before and none after, via Trace Search rather than SDK return values

Out of scope

Reproduced while investigating and deliberately not addressed here. Listing them so the boundary of this PR is explicit; no follow-up work is committed to.

  • @log on a generator loses more than trace ownership. Because _handle_call_result never runs, the span output is never recorded, logger.conclude() never runs, and the workflow span pushed in _prepare_call is never popped, leaving the span stack dirty for whatever runs next in that context. Repairing it means making _sync_log return _finalize_call's value, which changes observable behaviour for every decorated generator in existing user code. Generator support has no test coverage today.
  • Sync flush() and terminate() can construct the flush coroutine and abandon it un-awaited at interpreter exit, so a concluded-but-unflushed trace is lost at process exit rather than sent. Reproduces on main too.
  • _auto_conclude_trace() swallows a ValidationError when a child span's output type cannot be assigned to its parent, shipping the trace wholly unconcluded.
  • GalileoDecorator._prepare_call adopts client_instance.traces[-1] when a trace is already active, so under concurrency it can attach spans to a sibling's trace — and _finalize_call then releases that adopted id, exposing the sibling's still-open trace to an early flush.
  • openai/response_generator.py's _finalize() has no error path of its own, so a raise inside it skips the conclude for a streaming call.
  • handlers/openai_agents/handler.py calls datetime.fromisoformat(node.span_params.get("start_time_iso", "")) unguarded, which raises ValueError on a missing value; for a child node that runs after add_trace().
  • The ingestion-hook annotations, Callable[[TracesIngestRequest], None] across six files, reject the async hooks that _send_ingest_request supports at runtime.

Notes for reviewers

  • The partition and rebinding are await-free, so no task can append between them — but a second OS thread can, and that is reachable from a real deployment rather than only from a hypothetical no-GIL interpreter. GalileoLoggerSingleton._get_key keys on the thread name, and anyio names every worker "AnyIO worker thread", so all of FastAPI's synchronous endpoints share one logger and one list — while the synchronous flush() runs _flush_batch on a third (EventLoopThreadPool) thread. A start_trace() landing between the partition and self.traces = still_running is dropped outright, and the failed-send restore has the same read-modify-write shape. Measured: never hit in 950 trials at the default switch interval, but forcing the two partitions to align corrupts 282 of 300 trials, and a threading.Lock takes that to 0 of 300 — so what serialises it today is dispatch-arrival jitter, not the GIL slice. Pre-existing, and wider on main, which takes the whole list unconditionally, so this change does not introduce it. Not fixed here because the lock alone is not sufficient: an append that has already loaded the list object lands on the detached one, so the fix also needs in-place mutation (self.traces[:] = survivors) and identity-based survivor computation — it replaces the exact lines under review, so it belongs in its own change rather than this one.
  • The invariant to keep: if a component marks a trace as being built, every exit path should release it. Fix 3 bounds the cost of missing one — the trace ships unconcluded once its owner finishes, instead of being skipped until terminate() — but the mark is still the signal that stops a half-built send. Three components mark: logger.add_trace(), the decorator, and the OpenAI wrapper.
  • One place deliberately left unguarded: base_handler.commit() / base_async_handler.async_commit() would strand a trace if log_node_tree() raised between start_trace() and conclude(). I could not demonstrate it — log_node_tree reads with .get(), guards its own int conversion, and the add_*_span calls swallow — so guarding async_commit would mean a new try/finally on a hot path for a hypothetical. Left unguarded on that basis.
  • This does not make the trace list per-context. current_parent is a per-instance ContextVar; self.traces is not, and it is declared in galileo-core, so per-context storage is a cross-repo change. Out of scope here, and this fix costs no extra requests or clients, which per-context lists or per-context loggers both would.
  • flush() returning [] remains three-way ambiguous: nothing pending, a sibling already carried my trace, or a swallowed error. An individual task still cannot learn the fate of its own trace from the return value.
  • .gitignore gains a root-anchored /.local/ entry for local-only scratch and credentials. Anchored so it cannot also match a nested directory of the same name.

🤖 Generated with Claude Code


Generated description

Below is a concise technical summary of the changes proposed in this PR:
Prevent GalileoLogger from dropping, duplicating, or prematurely uploading traces shared by concurrent tasks and threads by partitioning batches, tracking trace ownership, and restoring failed sends. Update GalileoDecorator, OpenAI tracing, documentation, changelog, and tests to preserve complete trace delivery across flush, failure, cancellation, and abandoned-context flows.

TopicDetails
Concurrent trace flushing Protect shared trace batches by claiming the caller’s trace, holding sibling traces while their live owners build them, releasing abandoned traces, and restoring detached batches after failures or cancellation.
Modified files (3)
  • src/galileo/logger/logger.py
  • src/galileo/utils/singleton.py
  • tests/test_logger_batch.py
Latest Contributors(2)
UserCommitDate
fercor@cisco.comdocs(decorator): say w...August 18, 2026
bin@galileo.aifeat: support custom H...July 30, 2026
Tracing lifecycle flows Release trace-building ownership across decorated calls, generators, failed preparation, and OpenAI errors, while documenting flush semantics and validating affected application flows.
Modified files (7)
  • .gitignore
  • CHANGELOG.md
  • README.md
  • src/galileo/decorator.py
  • src/galileo/openai/__init__.py
  • tests/test_decorator.py
  • tests/test_openai.py
Latest Contributors(2)
UserCommitDate
fercor@cisco.comdocs(readme): state wh...August 18, 2026
abhinav@galileo.aifeat: add Agent Contro...May 13, 2026
Review this PR on Baz | Customize your next review

_flush_batch() took a live reference to self.traces, awaited the ingest, then
cleared the list unconditionally. Concurrent tasks share one logger, and therefore
one trace list, when they run on the same thread against the same project and log
stream. A trace appended during that await was not in the already-frozen payload,
so the clear discarded it - and its own flush() then found an empty list, sent
nothing, and still reported success. Silent data loss with no exception raised.

Hand the batch off before sending instead:

    logged_traces, self.traces = self.traces, []

A trace appended mid-flush now lands in the new list and is picked up by the next
flush. This also makes the return value honest, since it no longer aliases a list
that kept growing after the payload was built, and it stops two concurrent flushes
from sending the same trace.

Detaching first would have turned a failed ingest into data loss, because
previously the traces stayed in place and were retried, so the batch is restored on
failure. The send moved into _send_ingest_request() to keep the hook/client
branching readable inside the try.

Adds two tests: one holds the ingest await open, appends a second trace, and
asserts both reach the transport; the other covers the restore-on-failure path.
Only the network egress is mocked, so the shared list, the frozen payload and the
empty-list early return are all exercised for real.

Also ignores .local/ so local-only scratch and credentials cannot be committed.

Co-Authored-By: Claude <noreply@anthropic.com>
@codecov

codecov Bot commented Aug 15, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 95.45455% with 5 lines in your changes missing coverage. Please review.
✅ Project coverage is 83.85%. Comparing base (a1a0821) to head (033969b).

Files with missing lines Patch % Lines
src/galileo/logger/logger.py 93.90% 5 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main     #634      +/-   ##
==========================================
+ Coverage   83.62%   83.85%   +0.23%     
==========================================
  Files         124      124              
  Lines       11037    11133      +96     
==========================================
+ Hits         9230     9336     +106     
+ Misses       1807     1797      -10     

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@fercor-cisco
fercor-cisco marked this pull request as ready for review August 15, 2026 01:19
@fercor-cisco
fercor-cisco requested a review from savula15 August 15, 2026 01:19
Comment thread tests/test_logger_batch.py Outdated
Comment thread src/galileo/logger/logger.py
Comment thread src/galileo/logger/logger.py
@savula15
savula15 requested a review from pradystar August 15, 2026 14:54
fercor-cisco and others added 4 commits August 17, 2026 10:53
Detaching the batch before the ingest await made the restore path load-bearing,
but it was guarded by `except Exception`. `asyncio.CancelledError` derives from
BaseException, so cancelling an in-flight `async_flush()` dropped the detached
batch outright - strictly worse than clearing after the await, where cancellation
simply skipped the clear.

Also cover the duplicate-send guarantee the detach provides. The existing
concurrency test awaits the first flush before starting the second, so the two
never overlap, and its `set()` would fold away a repeated send. The new test holds
both flushes inside their ingest await at once and asserts payloads by
multiplicity; against the previous implementation it sees the first flush's trace
resent by the second.

Co-Authored-By: Claude <noreply@anthropic.com>
Concurrent tasks share one GalileoLogger, and therefore one trace list, so a
flush was sending traces a sibling task had started but not finished. The ingest
payload is serialised synchronously before the request is awaited, so those
traces reached the backend without their output, duration or later spans, and a
subsequent conclude() could only mutate an already-serialised model. Since the
batch is detached from the list, the owning task's own flush then found nothing
left to send and reported success, so nothing signalled the loss.

A flush now sends only traces no other context is still building. The flushing
caller always claims its own trace, so flushing an open trace still sends it;
terminate() releases everything so a trace whose owner never concluded it is not
stranded. @log leaves its trace open for a later decorated call in the same
context to reuse, so the decorator reports ownership explicitly rather than
relying on conclude().

Also stops _auto_conclude_trace() deriving a trace's inherited output from the
last entry of the shared list, which under concurrency stamped the flushing
task's trace with an output computed from a sibling's spans.

Co-Authored-By: Claude <noreply@anthropic.com>
start_trace() marks a trace as being built, and the wrappers skip
_finalize_call when _prepare_call raises - so a trace started just before
that failure had nothing left to report it as finished, and every later
flush from another context skipped it until terminate(). Release it where
the failure is handled, and mark ownership only once preparation has
actually completed.

Only reachable when a decorated call abandons its trace in a task that
never flushes, since a flush in the owning context claims its own trace;
the regression test therefore flushes from outside that task.

Co-Authored-By: Claude <noreply@anthropic.com>
The wrapper starts the trace itself when there is no active one, and only
APIStatusError is routed into the response processing that concludes it. A
connection error or timeout unwinds straight to the error path, so the trace
stayed marked as being built and every flush from another context skipped it
until terminate().

Report the hand-off on that path. The regression test flushes from outside the
failing call's task, since a flush in the owning context claims its own trace
and would mask the leak.

Co-Authored-By: Claude <noreply@anthropic.com>
@fercor-cisco fercor-cisco changed the title fix(logger): stop dropping traces appended during an in-flight flush fix(logger): only flush traces that no other task is still building Aug 18, 2026

@fercor-cisco fercor-cisco left a comment

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 This review was generated by the Astra agent (claude-opus-5). It may contain mistakes.

Verdict: request_changes — The core fix is well-reasoned and well-tested, but the new "hold back traces someone is still building" rule has no backstop: I verified two paths (manual start_trace() in a task that ends without conclude(), and @log on a generator function) where a trace is now never flushed at all, whereas main flushed it.

General Comments

  • 🟠 major (design): The "every marker must release" invariant has no backstop, and I verified two places where it is already violated.

The PR notes this risk itself ("if a component marks a trace as being built, every exit path must release it, or a flush from another context skips it until terminate()"). The problem is that the obligation is now spread across logger.add_trace(), GalileoDecorator._prepare_call, _safe_prepare_call, _finalize_call, _conclude, reset_parent_tracking, terminate, and the OpenAI wrapper — and a single missed path silently converts a degraded trace (previously shipped with a missing output) into a trace that is never shipped, plus an unbounded self.traces / _active_trace_ids leak in a long-running process. That is the exact customer-visible symptom this PR exists to fix (SAO-15919: "traces report local success but never appear in the console"), reintroduced through a different door.

I confirmed two concrete instances by running the same probe against main and this branch (details in the two line comments). Both require a context/task boundary — i.e. precisely the concurrency shape the PR targets.

Because holding back is unbounded, and because release correctness now depends on library code that swallows its own exceptions (_conclude and _auto_conclude_trace are both wrapped in warn_catch_exception, base_handler.commit() / openai_agents._commit_trace() can raise between start_trace() and conclude()), I don't think auditing release sites is sufficient on its own. Some bounded fallback would make the whole class safe:

  • Age-bounded hold-back — skip an unfinished trace only while now - trace.created_at < HOLD_BACK_MAX_SECONDS; past that, ship it. Bounds both the loss window and memory, and needs no new release sites.
  • Attempt-bounded hold-back — count how many consecutive flushes skipped each trace id and release after K. Deterministic and easy to test, though a genuinely long-running trace could still be shipped early.
  • Tie ownership to a liveness token rather than an id — e.g. store a weakref to the owning asyncio.Task/thread alongside the trace id, and treat a dead owner as released. Most precise, most work.

Note that simply clearing _active_trace_ids at galileo_context.__exit__ / flush_all() the way terminate() does is not safe: a context can exit while sibling tasks are still building traces, which would reintroduce defect (3).

Whichever you pick, please also state the guarantee in the _mark_trace_unfinished docstring so the next component that marks a trace knows what happens if it forgets to release.

  • 🟡 minor (testing): The 18 new tests are genuinely good — event-driven rather than sleep-based, real asyncio.Tasks so the contexts diverge while the list stays shared, and each one demonstrably fails when the code it protects is removed. What's missing is the negative direction of the new rule: every test asserts that a held-back trace is eventually sent by an owner that behaves correctly, and none asserts that a trace can never be held back forever by an owner that doesn't. test_terminate_sends_a_trace_abandoned_by_a_finished_task comes closest but confirms the opposite — it pins process exit as the only backstop.

A test of the shape "task starts a trace, ends without concluding, a flush from another context happens, assert the trace leaves" would have caught both regressions below, and would pin whatever bounded fallback you add.

Follow-ups

Suggested follow-up work that could be tracked as Jira tickets:

  • src/galileo/decorator.py:686-700: _prepare_call adopts client_instance.traces[-1] when has_active_trace() is true, which under concurrency can be a sibling task's trace. The PR author already flagged this as a known adjacent issue, but it now has a second consequence worth capturing in the same ticket: _finalize_call will call _mark_trace_finished() on that adopted id, releasing a trace the sibling is still building and exposing it to an early flush — i.e. defect (3) reachable through the adoption path.
  • src/galileo/openai/response_generator.py:67-78: ResponseGeneratorSync._finalize() runs in __iter__'s finally and is the only thing that concludes a trace the wrapper started for a streaming call. If extract_streamed_openai_response() raises on malformed items, or the caller abandons the stream without exhausting it, the trace is now held back from every flush rather than merely left unconcluded. Same class as the _wrap fix in this PR; worth an explicit release in _finalize's own error path once the backstop question above is settled.
  • src/galileo/handlers/openai_agents/handler.py:126-138: _log_node_tree calls datetime.fromisoformat(node.span_params.get("start_time_iso", "")) unguarded, which raises ValueError on a missing value. For child nodes this runs after add_trace() (line 132), so the raise propagates out of _commit_trace and skips both conclude() and the flush_on_trace_end flush — stranding the trace under the new hold-back rule. Same shape as the base_handler.commit() gap the PR describes as deliberately unguarded; both are worth revisiting together.

Comment thread src/galileo/logger/logger.py Outdated
Comment thread src/galileo/decorator.py
Comment thread src/galileo/decorator.py Outdated
Comment thread src/galileo/logger/logger.py Outdated
Comment thread .gitignore Outdated
@fercor-cisco fercor-cisco changed the title fix(logger): only flush traces that no other task is still building fix: only flush traces that no other task is still building Aug 18, 2026
fercor-cisco and others added 2 commits August 18, 2026 11:29
…orever

Holding a trace back until the context building it finishes is what stops a
sibling's flush shipping it half-built, but an owner can go away without
concluding - user code raising between start_trace() and conclude(), or
_conclude() swallowing a coercion error. Nothing could then claim it: the claim
is resolved from the caller's own parent chain, and the abandoned trace's chain
died with its owner. Every flush skipped it until terminate(), which does not
run at interpreter exit in an asyncio.run script, so the trace was lost rather
than merely late - the same silent non-delivery this change set exists to fix.

Ownership now records a weak reference to the owning asyncio task or thread, and
a flush holds a trace back only while that owner is alive. A missed release site
therefore costs a trace that ships unconcluded, not one that never ships.

claimed_trace_id loses its default: omitting it meant holding back the caller's
own trace too, which is the opposite of what the partition is for.

Co-Authored-By: Claude <noreply@anthropic.com>
_finalize_call wraps a generator result and returns the wrapper, but _sync_log
discards that return value and hands back the unwrapped generator, so the
wrapper is never iterated and _handle_call_result - the only place the decorator
reports it has stopped building the trace - never runs. Both generator kinds
land there: asyncio.iscoroutinefunction is False for an async generator
function. The trace was held back from every flush by a context that had
finished with it.

The hand-off is reported from _finalize_call instead, where both the discarded
and the kept wrapper pass. The guard is len(stack) <= 1 rather than an empty
stack, because only _handle_call_result pops this call's own span.

The failed-release log drops to debug: the likely raiser is the
get_logger_instance() call above it, whose failure the caller has already
reported, so it was a second message per decorated call with no trace to
release.

Co-Authored-By: Claude <noreply@anthropic.com>
@fercor-cisco

fercor-cisco commented Aug 18, 2026

Copy link
Copy Markdown
Contributor Author

Both general points taken, and both are now addressed — 9cca4394 and a21106fb. Detail on the two specific bugs is in the line threads; this is the design reasoning you asked for.

The backstop: owner-liveness

You were right that auditing release sites is not sufficient. Your review found two gaps; verifying them turned up a third (reset_parent_tracking() releases only the caller's own trace, so it does nothing for a finished task's), and the safety net the whole design leans on turned out not to exist: terminate() does not fire at interpreter exit in an asyncio.run script. Logging sends to a file so shutdown-time sends are captured, the branch recorded no send at all, with RuntimeWarning: coroutine 'GalileoLogger._flush_batch' was never awaited. That hole is pre-existing — a concluded-but-unflushed trace is lost the same way on main — but it means the worst case was never "one late batch at exit", it was loss.

Of your three options I took the third, in the task.done() form rather than the weakref-death form:

_mark_trace_unfinished() now stores a weak reference to the owning asyncio.Task (or thread, for synchronous callers), and the partition holds a trace back only while that owner is alive. _active_trace_ids: set[UUID] becomes _traces_being_built: dict[UUID, weakref.ref | None]. The whole check is await-free, so the partition stays atomic, and shipped ids are popped as before.

Why not the other two:

  • Age-bounded ships a legitimately long-running trace mid-build once it crosses the bound — reintroducing defect (3), the one this PR exists to fix — and needs a constant that nobody can defend. A twelve-minute agent run is not abandoned.
  • Attempt-bounded measures flush frequency, not abandonment. A server flushing every second releases a live 30-second trace after K flushes; a server flushing hourly never releases an abandoned one.
  • Liveness needs no constant, and it happens to cover all three gaps found so far, because each requires the owner to be a task that has already finished. A weakref that has died is strictly weaker than done(): the event loop holds a strong reference to a running task, so a completed task is usually still reachable from whatever gathered it. Checking done() catches it immediately; waiting for collection would not.

_mark_trace_unfinished's docstring now states the guarantee, as you asked: a marker that never releases costs a trace that ships unconcluded once its owner finishes, not one that is never sent at all.

Residuals, stated rather than implied. A same-thread, no-task abandonment is still held until terminate() — no regression, since that shape ships today via claimed_trace_id. And a child task that inherits an open trace through the copied context could be released early if the marking task ends first; @log re-marks on entry so decorator users are covered, raw-logger users in that shape are not.

The missing negative direction

Fair, and it was the gap that let both bugs through. test_flush_sends_a_trace_whose_owning_task_has_finished is the test you described, plus test_reset_parent_tracking_in_another_context_does_not_strand_a_trace for the third gap and two decorated-generator tests. Every new test was mutation-checked: with the liveness check disabled, the two logger tests fail; with the generator release removed, the two decorator tests fail; and with the hold-back disabled entirely, the three original hold-back tests fail — so the new backstop demonstrably did not hollow out the old rule.

Follow-ups

All three of yours reproduce as described, as do two more: the pre-existing generator breakage (_handle_call_result never running also means conclude() never runs and the workflow span is never popped) and the abandoned-coroutine warning at interpreter exit. All of it is out of scope for this PR.

Evidence for the whole change beyond the suite: the five-task reproduction still ships 5 traces, 0 duplicates, 0 missing outputs across the latency sweep; the sequential single-task shape is unchanged (5 sends, 5 traces, 0 duplicates); traces from tasks that finish without flushing still leave at galileo_context.__exit__ (5 shipped, 0 stranded); GalileoAsyncCallback driven concurrently is identical on both start_new_trace settings; suite 2093 passed / 5 skipped, stable across repeat runs under xdist with random ordering; ruff clean; mypy 34 errors on the changed files on main and 34 here, none in the new code.

Unanchored, `.local/` would also hide a nested directory of the same name -
`src/.local/`, `docs/.local/` - which is more than the entry is meant to cover.

Co-Authored-By: Claude <noreply@anthropic.com>
Comment thread src/galileo/decorator.py
Comment thread src/galileo/decorator.py
Comment thread src/galileo/logger/logger.py Outdated
Comment thread src/galileo/logger/logger.py Outdated
fercor-cisco and others added 2 commits August 18, 2026 12:22
Names the three silent failures a shared trace list produced and what a flush
now sends, so a reader upgrading can tell whether the bug reached them without
reading the PR.

Co-Authored-By: Claude <noreply@anthropic.com>
… thread

A pool worker outlives the job that started a trace, so holding the trace while
its owning thread is alive held it for the life of the worker. The next job on
that worker cannot claim it either: pools that copy the context per job - anyio,
and therefore FastAPI's synchronous endpoints - hand it an empty parent chain.
`main` sent that trace on the first flush, so this was a regression, not the
residual the description claimed it was.

A thread cannot be flushing and mid-build at the same time, so a synchronous
owner that is the thread asking for the flush is done with the trace. The thread
is captured before dispatch, next to the claimed trace id, because the sync
`flush()` runs `_flush_batch` on an `EventLoopThreadPool` thread and would
otherwise compare against a pool worker.

Compared by identity rather than name: anyio names every worker alike, so a name
comparison would let one worker's flush ship another worker's half-built trace,
which is the failure the hold-back exists to prevent.

Co-Authored-By: Claude <noreply@anthropic.com>
Comment thread src/galileo/logger/logger.py
Comment thread src/galileo/logger/logger.py
The override releases the trace marker as well as the parent chain, and it does
so for the caller's own trace only - the id comes from the caller's parent chain,
which is empty in any other context. A review round already misread this as a
general way to release an abandoned trace, so it is worth stating.

Co-Authored-By: Claude <noreply@anthropic.com>

@fercor-cisco fercor-cisco left a comment

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 This review was generated by the Astra agent (claude-opus-5). It may contain mistakes.

Verdict: request_changes — The core fix is sound and well tested, but the new release-site guard in _finalize_call is off by one for span types that push no span, which I reproduced shipping a sibling's half-built trace — the exact defect this PR exists to fix — and two of the new guard tests pass with the code they claim to protect removed.

General Comments

  • 🟡 minor (testing): Two of the new tests that are supposed to pin release sites are vacuous, because the liveness backstop added in Fix 3 masks the very leak they probe. Both do await asyncio.create_task(failing_request()), so the owning task is done by the time the flush runs and _still_being_built() returns False regardless of whether the release happened.

I verified this by mutation:

  • Deleting the self._release_trace_being_built() call from _safe_prepare_calltests/test_decorator.py::test_trace_is_not_stranded_when_span_setup_fails still passes.
  • Deleting the new _mark_trace_finished() block from openai/__init__.py::_wrap's excepttests/test_openai.py::test_trace_is_not_stranded_when_the_openai_call_raises_a_non_status_error still passes.

Each docstring justifies the cross-task flush with "a flush in the owning context claims its own trace and would mask the leak", which was true before the liveness bound but is no longer the only masking mechanism. The two decorated-generator tests get this right by holding the owner alive with an asyncio.Event; these two should do the same so the release is the only thing that can ship the trace.

While there: logger.reset_parent_tracking()'s own release is also unpinned — test_reset_parent_tracking_does_not_strand_its_trace passes with the _mark_trace_finished() call removed from reset_parent_tracking(), because a synchronous owner compared against the flushing thread is already treated as finished.

Follow-ups

Suggested follow-up work that could be tracked as Jira tickets:

  • src/galileo/logger/logger.py:1216-1226: In distributed mode start_trace() rebinds self.traces = [trace], discarding earlier traces while their _traces_being_built entries stay in the dict. Nothing but _flush_distributed()/terminate() clears them, so a long-lived distributed logger that starts many traces without concluding them accumulates dead entries. Batch mode is unaffected (shipped traces are popped). Consider popping the marks for traces dropped from the list here, or keying the dict cleanup off the list rebinding.

Comment thread src/galileo/decorator.py Outdated
Comment on lines +789 to +790
if len(_get_or_init_list(_span_stack_context)) <= 1:
self._release_trace_being_built()

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟠 major (bug): This guard is off by one whenever the decorated call pushed no span of its own, so a nested decorated generator releases the trace its caller is still building.

_prepare_call only pushes a span when not span_type or span_type in ["workflow", "agent"] (line 707). For @log(span_type="llm"|"tool"|"retriever") on a generator function, nothing is pushed, so inside an outer @log call the stack length is 1 (the outer call's span) and <= 1 fires — releasing the outer trace mid-build. The non-generator branch gets this right by requiring an empty stack (_handle_call_result, line 950).

Reproduced against this branch (mock ingest, real logger/list):

@log(span_type="llm")
def stream_tokens():
    yield "sunny"

@log
async def outer() -> str:
    list(stream_tokens())      # nested decorated generator
    started.set()
    await may_finish.wait()    # sibling flushes here
    return "outer done"

A sibling task's logger.flush() while outer is parked ships ('outer', None) — the trace goes out with no output and is detached from the list, so "outer done" never reaches Galileo. With stream_tokens changed to a plain (non-generator) function, the same probe correctly leaves outer behind and sends it later. That is defect (3) reachable through the new code, on plain public API.

Also worth a look while fixing: on the _async_log path the wrapper is kept (result = self._finalize_call(...), line 377), so releasing here happens before the generator is consumed and before _handle_call_result adds its output — a smaller premature-send window for @log async def f(): return gen().

Suggested change
if len(_get_or_init_list(_span_stack_context)) <= 1:
self._release_trace_being_built()
# Only this call's own span may still be on the stack, and only if it pushed one
# (see _prepare_call): otherwise a non-empty stack means an outer decorated call is
# still building the trace and must keep it.
pushed_own_span = not span_type or span_type in ("workflow", "agent")
if len(_get_or_init_list(_span_stack_context)) <= (1 if pushed_own_span else 0):
self._release_trace_being_built()

🤖 Generated by the Astra agent

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Confirmed on the structure and on the behaviour, and fixed in 1f93c00c. Your reading of _prepare_call
is exactly right: it pushes a span only when not span_type or span_type in ["workflow", "agent"], so for
@log(span_type="llm") on a generator the stack holds only the outer call's span, <= 1 fires, and the
outer trace is released mid-build.

Probed with a nested @log(span_type="llm") generator inside an outer @log async def, the outer parked on
an asyncio.Event, a sibling task flushing:

Tree marks at park sibling flush ships outer's "outer done" on main
nested generator, span_type="llm" 0 — released outer, span output null lost, 1 send identical
nested plain fn (control) 1 nothing shipped correctly
nested generator, workflow type (control) 1 nothing shipped correctly

This is the strongest of the six: plain public API, no handler, no async_flush, no custom code. It is also
not a regression (see the review-level note).

Your suggested guard is what shipped, with one substitution:

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):

is_concludable_span_type (already imported at :71) rather than a fourth copy of the literal — it is
verbatim the predicate gating the pop at :880, and whether the span was popped is what determines whether
it is still on the stack, so that is the honest source of truth. I deliberately left :707's literal alone:
behaviour-identical to change, but it adds an unrelated hunk to _prepare_call in an already ~1100-line
diff. Residual drift risk noted — adding a concludable type would update the pop and this threshold but not
the push.

One alternative I rejected, in case it comes up: moving the release into the generator wrappers is not
strictly better. The wrapper's finally runs only on exhaustion, close() or GC, so for x in gen(): break
inside a long-lived owner leaves the trace marked with a live owner — the liveness backstop cannot
rescue it and it is held to process exit. That trades a degraded trace for a lost one. It also cannot fire
on _sync_log, which discards _finalize_call's return value (:433).

Two tests (tests/test_decorator.py), sync span_type="llm" and async span_type="tool". Both park
the outer call on an asyncio.Event so Fix 3's liveness bound cannot mask the leak — your R5 point applied
pre-emptively — and both have the owner flush itself, because a foreign flush cannot auto-conclude the
trace (_auto_conclude_trace reads the caller's parent chain), which would leave trace.output None and
the assertion checking nothing. Red before the fix with the exact bug signature
[[('outer_forecast', None)]] == []; green after; the a21106fb pair still pins the pushed_own_span=True
branch. Full suite 2095 → 2097, flake loop 20× under xdist clean, mypy src/galileo/decorator.py 10 errors
on both sides → 0 new (note inv type-check excludes galileo.decorator).

Separately: the nested generator's own llm span never records its output on either branch. Pre-existing,
out of scope here, on the candidate list.

Comment thread src/galileo/decorator.py
Comment on lines +644 to 648
# 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.
self._release_trace_being_built()
return False

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The 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 _prepare_call fails it releases the trace the outer decorated call is still building, exposing it to a sibling's flush.

Confirmed with a probe that makes only the nested call's add_workflow_span raise (the same failure mode test_trace_is_not_stranded_when_span_setup_fails patches in): a sibling flush then ships ('outer', None) while the outer call is still parked on an await, and the outer's real output is lost with it.

The reachability is narrower than the generator case — most raisers inside _prepare_call are swallowed by warn_catch_exception — but the guard costs one line, and it also makes the intent explicit (this call, not its caller, owns the trace it started).

Suggested change
# 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.
self._release_trace_being_built()
return False
# 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. Only release when no outer decorated call
# is still building the trace: a nested failure must not release its caller's trace.
if not _get_or_init_list(_span_stack_context):
self._release_trace_being_built()

🤖 Generated by the Astra agent

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Confirmed and fixed in a3fb9f9a, which also closes your R5 point — the three test reworks came with it.

Reproduced with a depth-aware add_workflow_span patch (outer succeeds, nested raises) and the owner parked:
being_built: 0 at park, the sibling flush ships outer with span output null, "outer done" lost.
Identical on main. Two probe traps worth recording, because the first one nearly refuted it spuriously:
patching add_llm_span proves nothing (_prepare_call never calls it — patch add_workflow_span), and
without parking the owner the liveness bound masks the leak entirely.

Deviation from your fix, and I think it is strictly better. You suggested reading the stack inside the
handler; I snapshot it before the attempt:

outermost = not _get_or_init_list(_span_stack_context)
try:
    self._prepare_call(...)
except Exception:
    ...
    if outermost:
        self._release_trace_being_built()

Same cost. _prepare_call pushes at :716 and marks the trace at :729, so a raise landing between them
would leave the handler seeing this call's own span, skip the release, and leave the trace marked by
start_trace with nothing to release it. The snapshot answers "was there an enclosing decorated call"
regardless of how far preparation got.

Release-site audit, since your comment asks about scope. All ten _mark_trace_finished /
_release_trace_being_built sites checked; only this one lacked a correct guard. The OpenAI wrapper is
already safe — should_complete_trace starts False (openai/__init__.py:140) and is set True only in
the else of if galileo_logger.current_parent():, i.e. only when the chain was empty and the wrapper
itself called start_trace, so under an enclosing @log it cannot release the decorated call's trace.
reset_parent_tracking is ContextVar-isolated, _conclude is guarded by finished_step._parent is None,
_flush_batch pops only ids it detached, and the wholesale .clear() calls are distributed-mode
bookkeeping or deliberate lifecycle end. No shared helper added: there is no existing "did this context
start the trace" predicate, and factoring one for three sites of a two-line condition would mean
re-touching the two fixes already landed.

On reachability, you were right to hedge and I will go further. Every logger call _prepare_call makes
is wrapped in warn_catch_exception and swallows — start_trace, add_workflow_span, add_agent_span,
has_active_trace. The only genuinely escaping raiser is the bare client_instance.traces[-1] at
:691-692, i.e. the TOCTOU IndexError from the follow-up list. So the production trigger today is a
second bug, and the test's add_workflow_span failure is synthetic — fine for pinning the release site,
but I am not presenting it as a production shape.

Four tests, four distinct mutations, all verified separately. The first two are complementary and both
necessary — reverting the guard does not fail the top-level test, and deleting the release does not fail the
nested one:

Mutation Test that fails
Guard reverted (release unconditional) test_nested_span_setup_failure_does_not_release_the_outer_trace (new)
Release removed entirely test_trace_is_not_stranded_when_span_setup_fails (reworked)
mark-finished block removed from openai _wrap's except test_trace_is_not_stranded_when_the_openai_call_raises_a_non_status_error (reworked)
_mark_trace_finished removed from reset_parent_tracking() test_reset_parent_tracking_does_not_strand_its_trace (reworked)

The new test also failed pre-fix with [[('outer_forecast', None)]] == [].

Your R5 remedy needed one correction on the third test. The asyncio.Event trick fixes the first two.
It cannot fix the third: that owner is a thread, and _still_being_built treats an owner that is the
flushing thread as finished (flushing_thread is captured before dispatch). It now runs start_trace() +
reset_parent_tracking() on a spawned thread blocking alive on a threading.Event while MainThread
flushes — _mark_trace_unfinished falls back to threading.current_thread() with no running loop and
ContextVars are per-thread, so the spawned thread is the recorded owner and MainThread's claimed_trace_id
is None. All three docstrings were corrected too: they claimed the cross-task flush was the only masking
mechanism, which stopped being true when Fix 3 added owner liveness.

ef357fe3's original bug stays fixed — in the top-level-failure shape add_workflow_span raises
before the append, so the stack is empty, the guard fires, and the trace is still released and shipped
(verified with the owner alive; the probe's toplevel_fail result is byte-identical pre- and post-fix).
Suite 2098 passed / 5 skipped, inv type-check green, flake loops 20×/10× clean, 13 recorded artifact
checks all pass.

Comment on lines +2436 to +2439
# Exception, so cancelling an in-flight `async_flush()` would otherwise drop the
# detached batch outright.
self.traces = logged_traces + self.traces
raise

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 minor (bug): The restore puts the traces back but not their _traces_being_built entries, which were popped at line 2406-2407. So a failed or cancelled send strips the "still being built" mark from the batch it restores, and the next sibling flush can carry a genuinely half-built trace away.

This is reachable on the synchronous flush() path: _flush_batch runs on an EventLoopThreadPool thread, whose task context is a copy of that thread's (empty) context, so _auto_conclude_trace() sees an empty _parent_stack and concludes nothing. A caller that does start_trace(); add_*_span(); flush() therefore reaches the partition with its trace still marked; it is claimed, popped, and — if the ingest raises — restored unmarked. A concurrent task's flush then ships it with no output/duration, and the owner's later conclude() can no longer repair it since the trace is gone from the list.

Restoring the marks alongside the traces keeps the invariant symmetric (setdefault, so a mark re-taken meanwhile — e.g. @log re-entry — is not overwritten by the stale owner ref).

Suggested change
# Exception, so cancelling an in-flight `async_flush()` would otherwise drop the
# detached batch outright.
self.traces = logged_traces + self.traces
raise
try:
await self._send_ingest_request(traces_ingest_request)
except BaseException:
# The batch was detached before the send, so put it back for the next flush.
# Without this, detaching up-front would turn a failed send into data loss,
# whereas previously the traces stayed in place and were retried.
# BaseException, not Exception: `asyncio.CancelledError` does not derive from
# Exception, so cancelling an in-flight `async_flush()` would otherwise drop the
# detached batch outright. The ownership marks go back with them, or a sibling's
# flush would carry a still-unfinished trace away on the retry.
self.traces = logged_traces + self.traces
for trace_id, owner_ref in released_marks.items():
self._traces_being_built.setdefault(trace_id, owner_ref)
raise

🤖 Generated by the Astra agent

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Confirmed and fixed in d22439ec. It costs data, which the comment understates — but the stated
mechanism is refuted
, so please don't carry that explanation forward.

Owner does start_trace(); add_llm_span(); flush() and never concludes:

after start+span:        traces=['London'] marks=1
after OWN flush FAILED:  traces=['London'] marks=0   <-- restored UNMARKED
after FOREIGN flush:     shipped London

Severity variant: after the failed flush the owner adds a second span and concludes with its real answer —
already shipped and detached, so logger.traces is empty and the final answer never reaches the wire
(1 span shipped, 2 built).

Correction 1 — the reachability argument is wrong. Spying on _auto_conclude_trace, _parent_stack
depth inside _flush_batch is 1, not 0: async_run propagates a copy of the caller's context. So
auto-conclude does run, and the trace ships with a premature partial output, not output=None. Your
conclusion holds; the explanation does not.

Correction 2 — the literal suggestion restores nothing, and this is load-bearing. Capturing only the
marks the partition pops (:2406-2407) is too late: _auto_conclude_trace() runs first (:2380) and
_conclude releases the caller's own mark at :2085, so by the time the partition runs the one mark that
matters is already gone. The snapshot has to precede auto-conclude — which also means a whole-dict copy,
since the batch isn't known until after the partition. One entry per in-flight trace, negligible next to
the ingest request it guards.

marks_before_send = dict(self._traces_being_built)   # before _auto_conclude_trace()
...
except BaseException:
    self.traces = logged_traces + self.traces
    for trace in logged_traces:
        if trace.id in marks_before_send:
            self._traces_being_built.setdefault(trace.id, marks_before_send[trace.id])
    raise

setdefault not assignment, so a context that re-took the mark mid-flight isn't overwritten by the stale
owner ref; membership test not truthiness, because None is a legitimate value meaning "owner not
weak-referenceable, count it as alive". It cannot strand a trace: restored marks are re-tested by
_still_being_built on every later flush, and terminate() clears the dict wholesale.

test_failed_flush_keeps_holding_back_another_tasks_trace genuinely does not cover this, as you
suspected: its London lands in still_running and is never popped so its mark survives trivially, and its
New York is conclude()d, which releases the mark at :2084. No still-marked trace ever sits inside the
detached batch, which is the only exposing shape. The new test
(test_failed_flush_restores_the_ownership_mark_with_the_batch) puts one there and was red twice over
before the fix: assert UUID(...) in {}, and with that white-box line disabled, assert [['London']] == [].
Two mutations, cleanly separated — deleting the restore loop fails only the new test; deleting
self.traces = logged_traces + self.traces fails only the neighbour.

One accepted consequence, deliberately. An owner task retrying async_flush() after a failed send now
finds its own trace held back: the failed flush's finally cleared its parent chain, so it no longer
supplies claimed_trace_id, and _still_being_built has a thread-identity escape (owner is flushing_thread) but no task-identity one. Bounded — liveness releases it when the task ends,
terminate()/atexit ship it regardless, sync owners unaffected. The fix (capture flushing_task and thread
it into _still_being_built) re-touches the exact lines the reworked tests pin, so it is scope I declined
here rather than a thing I missed.

Also not a regression: main ships the same half-built trace on the foreign flush.

Suite 2099 passed / 5 skipped, mypy src/galileo/logger/logger.py 19 errors both sides → 0 new (note
inv type-check excludes galileo.logger, so the direct run is the only coverage), flake loop 20× clean,
and the probe flipped from CONFIRMED to REFUTED — the foreign flush still held London back.

Comment on lines +2398 to +2407
ready: list[LoggedTrace] = []
still_running: list[LoggedTrace] = []
for trace in self.traces:
if trace.id != claimed_trace_id and self._still_being_built(trace.id, flushing_thread):
still_running.append(trace)
else:
ready.append(trace)
logged_traces, self.traces = ready, still_running
for trace in logged_traces:
self._traces_being_built.pop(trace.id, None)

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 minor (bug): The PR notes argue the partition is atomic because it contains no awaits and "relies on the GIL for true threads". That reasoning does not cover a second OS thread appending to self.traces, which is reachable today: GalileoLoggerSingleton._get_key keys on the thread name, and anyio names every worker "AnyIO worker thread" — so all of FastAPI's synchronous endpoints share one logger and one list. Meanwhile the sync flush() runs this coroutine on an EventLoopThreadPool thread, i.e. a third thread. A start_trace() on worker W2 that lands between the loop finishing and self.traces = still_running (line 2405) is dropped outright — the same silent loss the PR is fixing. The self.traces = logged_traces + self.traces restore has the same read-modify-write window.

A threading.Lock held across partition + rebind (and across the restore) closes it and states the invariant explicitly, without affecting the async single-thread path. If you'd rather not add it, the notes should say the window is reachable from a real deployment shape rather than only from a hypothetical no-GIL interpreter.

🤖 Generated by the Astra agent

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Taking your alternative rather than the lock, and correcting the wording at two sites.

The measurement, first, because it is the reason for the split. The window is real: gating
_still_being_built so two flushing threads must both enter their partition before either proceeds
corrupts 282 of 300 trials (all ids duplicated), and a threading.Lock takes that to 0 of 300.
But it is not reachable by chance — 0 corruption in 950 trials at CPython's default switch interval,
and in every natural run the diagnostic "both threads got a non-empty batch" was 0, so the partitions
never even began concurrently. The partition costs ~1µs/trace (205µs at 200 traces, 4% of a 5ms slice),
so the GIL slice is not what protects it; what does is dispatch-arrival jitter through
random.choicecall_soon_threadsafe → self-pipe → loop wakeup. That is incidental, not an invariant,
which is exactly your point.

A lock over the partition and restore is not sufficient on its own, though, and this is why it is not
a two-line addition here. It fixes flush-vs-flush but not the orphaned append: self.traces.append(t)
loads the list object and then calls append, and the appender holds no lock, so if the partition
rebinds self.traces in between, the append lands on the detached list and the trace is lost anyway.
Closing it properly means stopping the rebind (self.traces[:] = survivors for the detach,
self.traces[:0] = logged_traces for the restore), computing survivors by identity immediately before
the write so a trace appended mid-partition is not wiped, and taking the lock at both append sites too —
~15 lines that replace the exact code this review round has been examining. It is worth doing; it is not
worth folding into this diff.

It is also pre-existing, and wider on main, which takes the whole list unconditionally — so this
change does not introduce the window (same framing as the review-level note).

Your anyio fact is right, and half of it is already handled in-branch_still_being_built compares
owner identity precisely because anyio names every worker alike (logger.py:1011-1014), and
tests/test_logger_batch.py spawns threads named literally "AnyIO worker thread" to pin it. What is new
here is connecting the shared list to the append/rebind race, which neither the marks nor the
liveness bound address at all. That connection is the useful part of this comment.

Both wording sites are corrected. The PR notes bullet now states the shape, the measurements and the
main comparison instead of the GIL. And logger.py:2403 — not in your ask, but the same overstatement
in the file you were reading — now reads: "This loop must stay free of awaits so no *task* can append
between the partition and the rebinding. It does not exclude a second OS thread: _get_key keys on
thread name, so anyio workers share one logger and one list, and that window is not closed here."

Comment thread src/galileo/decorator.py

Copy link
Copy Markdown
Contributor Author

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 for flush_all() at line 1197 (and, less visibly, GalileoLoggerSingleton.flush()/flush_all()).

Suggested change
Upload captured traces under a project and log stream context to Galileo.
Sends this caller's own trace, plus every trace no live context is still building; a trace
another context is part-way through building leaves with that context's flush instead. See
`GalileoLogger.flush()`.

🤖 Generated by the Astra agent

Copy link
Copy Markdown
Contributor Author

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 in 10405f1b. You are right that this is the flush most users
reach for and the shape in the originating ticket, and that cbdd0705 updated GalileoLogger.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 both
GalileoLoggerSingleton equivalents — with the wording lifted from logger.py:2155-2157 so the flush docs
read as one voice. A repo-wide grep for the stale phrasing across src/, tests/, README.md and
CHANGELOG.md found exactly these four, nothing else to chase. (Minor: the definitions are at
decorator.py:1147 and :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 return
None
. So on galileo_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 these
functions 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 -U0 inspected line by line, ruff clean,
mypy 12 errors both sides → 0 new, inspect.getdoc on all four renders with numpydoc Parameters
sections intact, suite unchanged at 2099 / 5.


fercor-cisco and others added 5 commits August 18, 2026 14:46
A generator decorated with a non-concludable span type pushes no span of its
own, so releasing the trace whenever the span stack held at most one entry
released it on behalf of the enclosing call. A sibling's flush then carried the
outer trace away mid-build, without its output and detached from the list, so
the outer call's own flush had nothing left to send.

Derive the threshold from whether this call pushed a span, using the same
predicate that gates the matching pop.

Co-Authored-By: Claude <noreply@anthropic.com>
_safe_prepare_call reports the hand-off when preparation raises, because the
wrappers then skip _finalize_call and nothing else would report it. But it
reported on the root of the caller's parent chain, which a nested call shares
with every enclosing call, so a nested failure handed the outer call's trace to
any concurrent flush while that call was still running.

Snapshot whether this is the outermost decorated call before the attempt, so the
answer cannot depend on how far preparation got before raising.

Hold the owner alive in the three tests that guard a release site. Each passed
with the code it protects removed: the owner had already finished, so a trace is
treated as no longer being built whether or not the release happened. The
reset_parent_tracking one needs a second thread rather than a parked task, since
an owner that is the flushing thread is already treated as finished.

Co-Authored-By: Claude <noreply@anthropic.com>
A failed or cancelled send puts its detached batch back, but the marks recording
who is still building those traces stayed popped. A trace whose owner had not
finished with it therefore came back unmarked, and the next flush from any other
context carried it away half-built - the premature send this guard exists to
prevent, reintroduced on the path that exists to prevent data loss.

Snapshot the marks before auto-concluding, which already releases the caller's
own trace before the batch is chosen, and put them back with setdefault so a
context that took a mark again meanwhile keeps it.

The existing failed-send test does not cover this: its held-back trace is never
detached and its own trace is concluded first, so no still-marked trace ever sits
inside the batch. The new one parks the owner alive after its flush fails, since
a trace whose owner has finished is nobody's to build any more.

Co-Authored-By: Claude <noreply@anthropic.com>
…reads

The comment above the flush partition claimed that staying free of awaits
meant nothing could append between the partition and the rebinding. That
holds for tasks, not for a second OS thread: `_get_key` keys on thread
name and anyio names every worker alike, so FastAPI's synchronous
endpoints share one logger and one trace list. Closing that window needs
in-place mutation and a lock, which is a separate change; say so here
rather than implying it is already covered.

Co-Authored-By: Claude <noreply@anthropic.com>
The README showed flush() in seven examples without saying what it covers. Two
things surprise people: a flush leaves a trace behind when another task is still
building it, and neither wrapper confirms your own trace was sent -
galileo_context.flush() returns nothing and swallows upload errors, while
logger.flush()'s empty list is three-way ambiguous (nothing pending, a concurrent
flush already carried the trace, or a swallowed error), so it cannot be read as
"not sent".

Co-Authored-By: Claude <noreply@anthropic.com>
…aces

galileo_context.flush() is the flush most users reach for, but its docstring still
promised "all captured traces" after the contract changed to hold back a trace
another live context is still building. The same overstatement sat on flush_all()
and on both GalileoLoggerSingleton equivalents, so an expected empty or partial
send read as a bug.

States the contract, not the mechanism: no ownership marks, owner liveness or
thread identity, since per-thread key isolation would change how traces group.

Co-Authored-By: Claude <noreply@anthropic.com>
@fercor-cisco

Copy link
Copy Markdown
Contributor Author

Five of the six are taken, in this PR. Before the individual threads, one correction that applies to R1,
R2 and R3 together, because it is the same error three times.

All three findings are correct and all three are reachable. None of them is a regression. The headline
says the _finalize_call guard ships "a sibling's half-built trace — the exact defect this PR exists to
fix", and R1's comment calls it "defect (3) reachable through the new code". Reachability is right;
"through the new code" is not. I probed each shape against this branch and against main a1a08217:

Shape branch 02cff04c main a1a08217
R1 nested span_type="llm" generator outer ships output-less, "outer done" lost identicalmain has no hold-back at all
R2 nested _prepare_call failure outer ships output-less identical
R3 failed send strips the marks foreign flush ships a partial trace identical

So these are gaps in the new guarantee, not damage the fix introduces — the branch is never worse than
main in any shape I could construct. That distinction matters for the merge decision, and it is worth
saying plainly because the PR body invited the error: its own completeness prose over-claimed, and this
round inherited the overstatement rather than disproving it. Both the body and logger.py:2403 are now
corrected.

Landed: R1 1f93c00c, R2 + R5 a3fb9f9a, R3 d22439ec, R4's wording 53e5f7e0 + the PR body, R6
10405f1b + 033969b3. Suite 2095 → 2099 passed / 5 skipped. R4's lock is declined here with
measurements, in its thread. The distributed-mode mark leak is listed as out of scope, not promised.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant