Skip to content

fix: log and uncache OTel spans that end on another thread - #941

Open
sangkyoonnam wants to merge 2 commits into
apache:mainfrom
sangkyoonnam:fix/otel-span-map-thread-leak
Open

sangkyoonnam wants to merge 2 commits into
apache:mainfrom
sangkyoonnam:fix/otel-span-map-thread-leak

Conversation

@sangkyoonnam

@sangkyoonnam sangkyoonnam commented Oct 4, 2026 •

Copy link
Copy Markdown

With use_otel_tracing=True, a span opened inside an action on a worker thread that only attaches the OTel context is never logged to the Burr tracker, and its entry stays in the module-level span_map for the life of the process.

BurrTrackingSpanProcessor looks up the tracker through the tracker_context ContextVar. ThreadPoolExecutor doesn't copy context vars, so a worker that only attaches the OTel context sees no tracker. on_start still caches the span, but on_end only logs and uncaches it when a tracker is present. The same happens to a span that ends after post_run_step, which clears the context var.

Repro: an action that runs one child span in a ThreadPoolExecutor worker with context.attach(ctx), stepped 50 times with the local tracker. On main, len(span_map) is 50 and the log has 0 begin_span and 0 attribute records. Without the thread, or with this change, it's 0, 50 and 50. Plain synchronous MapStates doesn't reproduce this, since each sub-application sets the context var in its executor thread, but a worker inside a child action still does.

Changes

  • FullSpanContext carries the tracker that started the action span. When tracker_context is unset, a child span takes its parent's tracker. This covers the "track a map of span ID -> tracker" TODO for the unset case.
  • The processor still uses tracker_context when it's set, so tracker selection doesn't change there.
  • on_end removes the cache entry before calling the tracker, so a missing tracker or a failing tracker call can't leave it behind.

How I tested this

  • Four new tests with a local TracerProvider cover a child span on a worker thread, a span that ends after post_run_step, a tracker whose post_end_span raises, and a span the outer action opens after a nested app step. The existing none-tracker on_end test now also asserts the entry is removed. Those five cases fail on main and pass here; the same-thread variant of the first test passes on both as a control.
  • pytest tests --ignore=tests/integrations/persisters --ignore=tests/integrations/test_bip0042_bedrock.py: 661 passed, 2 skipped.
  • pre-commit run on both files passes.

Notes

  • Not covered: if pre_start_span raises in on_start, the entry still stays in span_map, as on main, and it now also holds the tracker.
  • I wrote this with Claude Code and reviewed and ran it myself.

Checklist

  • PR has an informative and human-readable title (this will be pulled into the release notes)
  • Changes are limited to a single goal (no scope creep)
  • Code passed the pre-commit check & code is left cleaner/nicer than when first encountered.
  • Any change in functionality is tested
  • New functions are documented (with a description, list of inputs, and expected output)
  • Placeholder code is flagged / future TODOs are captured in comments
  • Project documentation has been updated if adding/changing functionality.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@github-actions github-actions Bot added the area/integrations External integrations (LLMs, frameworks) label Oct 4, 2026

@CanReader CanReader left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Nice fix. I ran the otel and tracking tests on the branch and they pass, and the new tests fail on main. I also tried it with a real app where every step starts a child span on a ThreadPoolExecutor worker: on main nothing gets logged for those spans and span_map keeps growing, on this branch everything is logged and span_map ends empty.

Some things for later, not blocking:

  • The real cause looks like post_run_step doing tracker_context.set(None) instead of resetting to the old value. If you run a sub application inside an action, the outer app loses its tracker for the rest of that action. Your fallback covers this now (I checked, outer spans get their end_span again), but saving the token in pre_run_step and calling tracker_context.reset(token) would fix it at the source. A test for this nested case would be nice too since it's fixed but not tested.
  • _tracker_for still prefers the context var over cached_span.tracker, so a span can still be logged to another app's tracker. Same as main so not a regression, just wondering if the owner tracker should win now that we store it.
  • FullSpanContext now keeps a reference to the tracker, so if an entry still leaks (for example pre_start_span raising in on_start) the tracker and its log file stay alive with it. Small thing, maybe a follow up.

@sangkyoonnam

sangkyoonnam commented Oct 5, 2026 •

Copy link
Copy Markdown
Author

Thanks for running it against a real app. Agreed that post_run_step doing set(None) is the root cause. I added the nested-app test in 8e461a3; it fails on main, leaving the outer action span and after_inner in span_map, and passes here. I didn't switch to reset(token) here because in stream_result the post_run_step call comes from the result container's callback, which can run after the caller has moved to another context, and reset raises a ValueError there. I'll try the token approach in a follow-up. Preferring the owner tracker probably makes sense now that it's stored, but it changes which app gets the span when both are set, so I'd put it in that follow-up too.

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

This branch has not been deployed

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

Labels

area/integrations External integrations (LLMs, frameworks)

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants