Skip to content

fix(agent-server): surface _emit_event_from_thread executor failures - #4392

Open
Shailendra005 wants to merge 2 commits into
OpenHands:mainfrom
Shailendra005:fix/surface-emit-event-failures
Open

fix(agent-server): surface _emit_event_from_thread executor failures#4392
Shailendra005 wants to merge 2 commits into
OpenHands:mainfrom
Shailendra005:fix/surface-emit-event-failures

Conversation

@Shailendra005

Copy link
Copy Markdown

HUMAN:

Grabbed this one because a dropped stats event leaving no trace is the kind of thing you only notice long after it mattered. Small change, but the test needed a real assertion rather than "no exception raised".


AGENT:

Why

_emit_event_from_thread schedules locked_on_event with run_in_executor and discards the returned future. If _on_event raises inside the executor thread — a full disk, a serialisation error, broken state — nothing observes the failure. The event is lost and the only trace is Python's GC-time Future exception was never retrieved warning, which is easy to miss or lose entirely in production logging.

Both callers are non-async callbacks on hot paths: _setup_llm_log_streaminglog_callback (every LLM completion log) and _setup_stats_streamingstats_callback (every per-turn token-usage update). Reported in #4386.

Summary

  • Attach a done-callback to the future so an executor failure is logged at ERROR with the event kind and traceback, instead of being collected unread.
  • Added _log_emit_failure, a module-level helper that ignores cancellation and only reports a real exception.
  • Adjusted one existing test's stub: test_emit_event_from_thread_uses_captured_loop had run_in_executor return None, which the real API never does. It now returns a mock future. I preferred fixing the stub over adding a None guard in production, since a guard would imply a return value that cannot occur.

Issue Number

Closes #4386

How to Test

tests/agent_server/test_event_service.py::TestEmitEventFromThreadFailures::test_emit_failure_is_logged drives the real method with a conversation whose _on_event raises, then asserts the failure reaches the log.

$ OPENHANDS_SUPPRESS_BANNER=1 uv run pytest tests/agent_server/test_event_service.py -k EmitEventFromThreadFailures -q
1 passed

Reverting just the done-callback makes it fail, and the captured output is the reported symptom:

AssertionError: emission failure was not surfaced; captured=[
  "Future exception was never retrieved\nfuture: <Future finished exception=RuntimeError('disk full')>"
]

Worth noting for review: my first version of this test asserted loosely and passed with the fix reverted, so it proved nothing. The assertion now matches the specific message.

Full suite and checks:

$ OPENHANDS_SUPPRESS_BANNER=1 uv run pytest tests/agent_server -q
1917 passed, 13 deselected

$ uv run ruff check <changed files>      # All checks passed!
$ uv run ruff format --check <changed>   # unchanged
$ uv run pyright openhands-agent-server/openhands/agent_server/event_service.py
0 errors, 0 warnings, 0 informations

Scope

Logging only — the failure is surfaced, not retried, and the event is still dropped. Making these emissions durable is a larger change and belongs with the buffering discussion rather than here.

The issue notes #4077 item 3 describes the same discarded-future pattern in _publish_stream_delta (asyncio.run_coroutine_threadsafe). I left it alone to keep this reviewable; happy to follow up there with the same treatment if you want them consistent.

Comment thread openhands-agent-server/openhands/agent_server/event_service.py Outdated
Comment thread openhands-agent-server/openhands/agent_server/event_service.py
@Shailendra005

Copy link
Copy Markdown
Author

@VascoSch92 thanks — both addressed in 4f9e02b.

Foreign-thread add_done_callback. Good catch, and confirmed in CPython: Future.add_done_callback takes the self._loop.call_soon(fn, self) branch whenever the future is already settled, so attaching from an executor thread neither is thread-safe nor wakes an idle loop. Since this helper exists precisely to be called off-loop, a fast-failing emission could have left the report queued indefinitely — exactly the silence this PR is meant to remove. The attach now goes through call_soon_threadsafe, so it happens on the loop thread and the loop is woken.

test_callback_is_attached_from_the_loop_thread pins it: with the previous direct attach it fails with done-callback must be attached via call_soon_threadsafe.

Uncovered cancelled() branch. Added test_cancelled_future_is_not_reported, which cancels a real future and asserts the helper neither logs nor raises, so reordering the checks would surface as a failure rather than a leaked CancelledError.

Full suite 1919 passed, ruff and pyright clean.

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

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

agent-server: _emit_event_from_thread silently drops exceptions — stats and LLM-log events lost without any signal

2 participants