Skip to content

fix(runtime): bound the tracer flush wait on streaming responses - #730

Closed
aidandaly24 wants to merge 1 commit into
aws:mainfrom
aidandaly24:fix/bounded-sync-trace-flush
Closed

aidandaly24 wants to merge 1 commit into
aws:mainfrom
aidandaly24:fix/bounded-sync-trace-flush

Conversation

@aidandaly24

@aidandaly24 aidandaly24 commented Nov 3, 2026 •

Copy link
Copy Markdown
Contributor

Issue #, if available: Regression from #721 (follow-up to #629).

Description of changes:

What

  • Bound how long a response waits for _flush_tracer_provider(), which runs at the end of every streamed /invocations response. The flush now runs on a daemon thread and the caller waits for it with join(timeout) instead of relying on force_flush(timeout_millis=...).
  • Lower the flush cap from 30 s to 5 s, for both the sync and async paths.
  • Log a warning when a flush overruns the cap.
  • Skip the flush that _handle_invocation ran before returning a streaming response. It only delayed the response headers: the stream wrapper flushes again when the stream ends. Non-streaming responses still flush before they return.

Why

Since 1.25.2 (#721), sync-generator streams end with finally: _flush_tracer_provider(), and that call had no wait cap. Async-generator entrypoints are bridged to a sync generator (_async_gen_to_sync_gen), so they take the same path. Only the async helper had a cap, via asyncio.wait_for.

The timeout passed to force_flush does not bound the wait:

  • In opentelemetry-sdk 1.45, BatchProcessor.force_flush ignores timeout_millis and exports until the queue is empty.
  • AgentCore Runtime injects OTEL_EXPORTER_OTLP_TIMEOUT=5000, which the OTel Python exporter reads as seconds.

So on a runtime whose network has no route to the OTLP endpoint (for example VPC mode with no NAT and no X-Ray interface endpoint), a streamed response sends every event and then never closes:

  • Clients that read to the end of the stream time out. With default boto3 settings that is a ReadTimeoutError 60 s after the last event.
  • In our reproduction the flush stayed blocked for over 30 minutes.
  • Only the first invocation in a session is affected, because _flush_lock makes later invocations skip the flush while the first one is stuck.

The pre-stream flush had a smaller version of the same problem. If spans were already queued when a streaming request arrived, it held the headers for up to the cap, and the end-of-stream flush was then skipped because the lock was taken.

How

  • _flush_tracer_provider takes _flush_lock without blocking, starts a daemon thread that calls force_flush and releases the lock when it returns, and waits at most timeout_millis.

  • Lock semantics. A flush that overruns keeps holding _flush_lock until it really returns, so later calls skip it instead of piling up threads behind it. If the thread can't be started, the lock is released at once.

  • Spans are not dropped. Spans the flush misses stay queued for the batch processor's background exporter.

  • Why 5 s.

    • A healthy OTLP export takes tens of milliseconds (28–79 ms measured below), so 5 s is wide headroom.
    • It equals the export timeout the platform intends (OTEL_EXPORTER_OTLP_TIMEOUT=5000 ms).
    • It keeps a broken exporter from adding more than a few seconds to the end of a response, well under common client read timeouts.
    • 30 s was long enough that clients noticed it.
  • Async path. _flush_tracer_provider_async already bounded the response wait with wait_for(to_thread(...)), but the stuck flush kept a default-executor thread busy, and asyncio.run waits for that thread when the loop shuts down. Because the inner call is now bounded, the executor thread returns at the cap.

    Measured on Python 3.10, 3.11, 3.12 and 3.13 with a provider whose force_flush ignores the timeout and blocks for 20 s:

    response wait asyncio.run returns after
    before 0.20 s ~20 s, the full flush
    after 0.20 s 0.21 s
  • What this does not change. Process exit can still wait for a stuck export, because OTel's own atexit provider shutdown waits for it. With opentelemetry-sdk 1.45.1, a BatchSpanProcessor and an exporter blocked for 15 s:

    • The response-path flush now returns at the cap: 0.50 s, versus 15 s before.
    • The process still takes about 15 s to exit.

    Bounding that needs a correct exporter timeout, for example a platform value that OTel Python reads correctly. It is outside this SDK.

Testing

Unit: uv run pytest tests/ --cov=src --cov-branch: 3773 passed, 10 skipped, 4 xpassed. Coverage is 91.20% in total, 96.01% for runtime/app.py and 90.0% for runtime/tracing.py.

New and updated tests:

  • test_stream_closes_when_force_flush_ignores_timeout[sync_generator|async_generator] (test_app.py). It uses a tracer provider whose force_flush ignores timeout_millis and blocks once spans are pending. Before this change the /invocations stream does not finish (the test fails after 5 s); after it, the stream closes.
  • test_stream_headers_not_delayed_by_flush_of_earlier_spans (test_app.py). Spans are already queued when the request arrives, and the response must not wait on a pre-stream flush.
  • test_returned_async_generator_flushes_after_stream_finishes (test_app.py) covers the async stream path.
  • The existing sync and async stream flush tests are updated, since streams now flush once, at the end.
  • test_flush_wait_is_bounded_when_provider_ignores_timeout (test_tracing.py). It checks the bounded wait and the lock behaviour: a concurrent flush is skipped while the abandoned one runs, and the next flush runs after it finishes.
  • test_lock_is_released_when_flush_thread_cannot_start (test_tracing.py).

Each of these fails without the corresponding source change and passes with it. The runtime test package also passes on Python 3.13.

Lint:

  • uv run pre-commit run --all-files passes (ruff, ruff-format and the other hooks).
  • bandit passes.
  • mypy reports no new errors in the changed files.

End to end on AgentCore Runtime. Setup:

  • A VPC-mode runtime with no route to xray.<region>.amazonaws.com.
  • An async-generator streaming agent image with opentelemetry-sdk 1.45.1 and ADOT 0.22.0.
  • The platform injects OTEL_EXPORTER_OTLP_TIMEOUT=5000.
  • Each run invokes 5 new sessions with InvokeAgentRuntime, reading the full stream with a 60 s read timeout.
  • Results are for this branch's final commit, with the earlier runs agreeing.
Image Result (5 new sessions each)
bedrock-agentcore 1.25.2 all events through metadata arrive at about 1 s, then the stream never closes: 5/5 ReadTimeoutError at about 61 s, in each of 3 rounds
this branch 5/5 close 5.005–5.007 s after metadata, with headers at 0.4–0.5 s. The second invoke in each session closes 2–4 ms after metadata (flush skipped). One Tracer provider flush did not finish within 5000 ms warning per session
this branch, X-Ray reachable through a VPC endpoint 10/10 close 34–72 ms after metadata. 10 traces (50 spans) exported, no export errors

Known trade-off and follow-up

In a network with no route to the OTLP endpoint, the first response of each session still closes up to 5 s late, where 1.25.1 had no delay. Removing that needs the flush to move off the response path: close the response at once, and keep the session from being frozen or reclaimed while a bounded flush finishes. That depends on how AgentCore Runtime treats a session after the response (for example whether HealthyBusy from /ping defers a freeze), so it is left to a follow-up. This change stops the hang and is compatible with that design.

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

@agentcore-devx-automation

Copy link
Copy Markdown
Contributor

Claude Security Review: no high-confidence findings. (run)

@agentcore-devx-automation agentcore-devx-automation Bot removed the claude-security-reviewing Claude Code /security-review in progress label Nov 3, 2026
@codecov-commenter

codecov-commenter commented Nov 3, 2026 •

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
⚠️ Please upload report for BASE (main@3707a9f). Learn more about missing BASE report.

Additional details and impacted files
@@           Coverage Diff           @@
##             main     #730   +/-   ##
=======================================
  Coverage        ?   89.68%           
=======================================
  Files           ?      130           
  Lines           ?    11365           
  Branches        ?     1763           
=======================================
  Hits            ?    10193           
  Misses          ?      768           
  Partials        ?      404           
Flag Coverage Δ
unittests 89.68% <100.00%> (?)

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ 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.

Since 1.25.2, sync-generator streams (including async-generator entrypoints,
which are bridged to a sync generator) end with an uncapped
_flush_tracer_provider(). OTel SDK 1.45's BatchProcessor.force_flush ignores
timeout_millis, and AgentCore Runtime's OTEL_EXPORTER_OTLP_TIMEOUT=5000 is read
as seconds, so with no route to the OTLP endpoint the response streams every
event and then never closes.

Run force_flush on a daemon thread and stop waiting after the cap, lowered
from 30 s to 5 s. An overrunning flush keeps _flush_lock until it returns, so
later calls skip instead of stacking threads. This also frees the async
path's executor thread at the cap, so a stuck flush no longer blocks event
loop shutdown.

Streaming responses no longer flush in _handle_invocation before they are
returned: the stream wrapper flushes when the stream ends, and the extra
flush could only hold back the response headers.
@agentcore-devx-automation agentcore-devx-automation Bot added the claude-security-reviewing Claude Code /security-review in progress label Nov 3, 2026
@agentcore-devx-automation

Copy link
Copy Markdown
Contributor

Claude Security Review: no high-confidence findings. (run)

@agentcore-devx-automation agentcore-devx-automation Bot removed the claude-security-reviewing Claude Code /security-review in progress label Nov 3, 2026
@jariy17

jariy17 commented Nov 4, 2026

Copy link
Copy Markdown
Contributor

Closing this PR in favor of reverting the problematic PR.

@jariy17 jariy17 closed this Nov 4, 2026

This branch had an error being deployed

1 failed deployment
auto-approve — daf319cc Deployed Nov 3, 2026 by aidandaly24 via Test (evaluation) #1686
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/m PR size: M

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants