fix(events): log full exception details in ReactiveEventBus.emit() error handlers
CI / build (pull_request) Successful in 21s
CI / helm (pull_request) Successful in 22s
CI / lint (pull_request) Successful in 3m19s
CI / quality (pull_request) Successful in 3m48s
CI / security (pull_request) Successful in 4m6s
CI / typecheck (pull_request) Successful in 4m17s
CI / integration_tests (pull_request) Successful in 6m50s
CI / unit_tests (pull_request) Successful in 7m19s
CI / docker (pull_request) Successful in 1m33s
CI / e2e_tests (pull_request) Successful in 11m31s
CI / coverage (pull_request) Successful in 11m49s
CI / status-check (pull_request) Successful in 1s
CI / benchmark-publish (pull_request) Has been skipped
CI / benchmark-regression (pull_request) Successful in 51m59s
CI / build (pull_request) Successful in 21s
CI / helm (pull_request) Successful in 22s
CI / lint (pull_request) Successful in 3m19s
CI / quality (pull_request) Successful in 3m48s
CI / security (pull_request) Successful in 4m6s
CI / typecheck (pull_request) Successful in 4m17s
CI / integration_tests (pull_request) Successful in 6m50s
CI / unit_tests (pull_request) Successful in 7m19s
CI / docker (pull_request) Successful in 1m33s
CI / e2e_tests (pull_request) Successful in 11m31s
CI / coverage (pull_request) Successful in 11m49s
CI / status-check (pull_request) Successful in 1s
CI / benchmark-publish (pull_request) Has been skipped
CI / benchmark-regression (pull_request) Successful in 51m59s
Add exc_info=True to both _logger.warning() calls in
ReactiveEventBus.emit(): the per-handler exception block
("event_handler_failed") and the RxPY stream error block
("reactive_stream_error"). Both handlers already logged
error=str(exc) (the exception message text) and error_type, but
omitted the traceback. With exc_info=True structlog now forwards the
full traceback to the configured log output, giving developers the
diagnostic detail needed to debug subscriber and stream failures in
production.
Remove the @tdd_expected_fail tag from the traceback scenario in
features/tdd_event_bus_exception_swallow.feature so that all three TDD
scenarios (#988) run as normal regression guards. Add a third scenario
covering the RxPY stream error path (reactive_stream_error) to verify
exc_info is forwarded when the Subject dispatch raises. Update the
feature description and step-definition docstring to reflect the fixed
state and full coverage of both error paths.
Fix CHANGELOG entry to accurately describe the pre-existing state:
str(exc) was already logged; only exc_info=True was missing.
ISSUES CLOSED: #988
This commit is contained in:
@@ -2,6 +2,14 @@
|
||||
|
||||
## Unreleased
|
||||
|
||||
- Fixed `ReactiveEventBus.emit()` exception handlers to enable traceback
|
||||
forwarding (`exc_info=True`). The per-handler exception block already
|
||||
logged `error=str(exc)` and `error_type`, but omitted `exc_info=True`,
|
||||
so no traceback was forwarded to the configured log output. The RxPY
|
||||
stream error handler had the same omission. Both now include
|
||||
`exc_info=True` so that structlog forwards the full traceback. Removed
|
||||
`@tdd_expected_fail` tag from the TDD test so all three scenarios run as
|
||||
normal regression guards. (#988)
|
||||
- Implemented `--mount` flag on `resource add container-instance`. Supports
|
||||
resource-reference mounts (`--mount local/api-repo:/workspace`) and
|
||||
host-path mounts (`--mount /var/config:/config:ro`). Multiple `--mount`
|
||||
|
||||
@@ -1,13 +1,12 @@
|
||||
"""Step definitions for tdd_event_bus_exception_swallow.feature.
|
||||
|
||||
This test captures bug #988: ReactiveEventBus.emit() swallows exception
|
||||
details. The exception handler logs only ``type(exc).__name__`` and omits
|
||||
``str(exc)`` and ``exc_info=True``, making production debugging impossible.
|
||||
Regression guard for bug #988: ReactiveEventBus.emit() previously omitted
|
||||
``exc_info=True`` in both the per-handler exception block and the RxPY
|
||||
stream error block, so no traceback was forwarded to the log output when
|
||||
a subscriber or stream observer raised an exception.
|
||||
|
||||
The scenario is tagged ``@tdd_expected_fail`` so the underlying assertion
|
||||
failure (confirming the bug exists) is inverted to a CI pass. Once the
|
||||
fix for #988 is merged, remove the ``@tdd_expected_fail`` tag from the
|
||||
feature file and this test will run normally as a regression guard.
|
||||
Bug #988 has been fixed. The ``@tdd_expected_fail`` tag has been removed
|
||||
and all scenarios now run as normal regression guards.
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
@@ -102,3 +101,59 @@ def step_then_log_contains_traceback(context: Context) -> None:
|
||||
f"The handler must call logger.warning(..., exc_info=True) so that "
|
||||
f"the full traceback appears in production logs. Log entry: {log_entry}"
|
||||
)
|
||||
|
||||
|
||||
# -- Stream error path steps -----------------------------------------------
|
||||
|
||||
# Distinctive error for the RxPY stream observer failure.
|
||||
_STREAM_ERROR_MESSAGE = "stream observer failure for debugging"
|
||||
|
||||
|
||||
@given("a ReactiveEventBus with a stream observer that raises a RuntimeError")
|
||||
def step_given_bus_with_failing_stream_observer(context: Context) -> None:
|
||||
"""Create a ReactiveEventBus and attach a stream observer that raises."""
|
||||
context.bus = ReactiveEventBus()
|
||||
|
||||
def _failing_observer(event: DomainEvent) -> None:
|
||||
raise RuntimeError(_STREAM_ERROR_MESSAGE)
|
||||
|
||||
# Subscribe directly on the RxPY stream so that on_next raises inside
|
||||
# the Subject dispatch, triggering the reactive_stream_error handler.
|
||||
context.bus.stream.subscribe(on_next=_failing_observer)
|
||||
|
||||
|
||||
@when("I emit an event that triggers the stream error")
|
||||
def step_when_emit_stream_error(context: Context) -> None:
|
||||
"""Emit a PLAN_CREATED event and capture structlog output."""
|
||||
with structlog.testing.capture_logs() as captured:
|
||||
context.bus.emit(DomainEvent(event_type=EventType.PLAN_CREATED))
|
||||
context.captured_logs = captured
|
||||
|
||||
|
||||
@then("the warning log for the stream error should contain traceback information")
|
||||
def step_then_stream_error_log_contains_traceback(context: Context) -> None:
|
||||
"""Assert the RxPY stream error log entry includes ``exc_info``.
|
||||
|
||||
The ``reactive_stream_error`` handler in ``emit()`` must forward the
|
||||
full traceback via ``exc_info=True`` so that RxPY stream failures are
|
||||
diagnosable in production logs.
|
||||
"""
|
||||
warning_logs = [
|
||||
entry
|
||||
for entry in context.captured_logs
|
||||
if entry.get("log_level") == "warning"
|
||||
and entry.get("event") == "reactive_stream_error"
|
||||
]
|
||||
assert warning_logs, (
|
||||
f"Expected a 'reactive_stream_error' warning log entry, "
|
||||
f"but captured logs were: {context.captured_logs}"
|
||||
)
|
||||
|
||||
log_entry = warning_logs[0]
|
||||
|
||||
assert log_entry.get("exc_info"), (
|
||||
f"Bug #988: The 'reactive_stream_error' warning log entry is missing "
|
||||
f"'exc_info' (traceback). The handler must call "
|
||||
f"logger.warning(..., exc_info=True) so that the full traceback "
|
||||
f"appears in production logs. Log entry: {log_entry}"
|
||||
)
|
||||
|
||||
@@ -5,17 +5,14 @@ Feature: TDD Issue #988 — ReactiveEventBus.emit() swallows exception details
|
||||
exception message and traceback
|
||||
So that I can diagnose why a subscriber failed without guessing
|
||||
|
||||
This test captures bug #988. The exception handler in
|
||||
ReactiveEventBus.emit() currently logs only `type(exc).__name__`
|
||||
(e.g. "ValueError") without `str(exc)` or `exc_info=True`. When a
|
||||
subscriber raises, the log contains no diagnostic detail — no message,
|
||||
no traceback, no clue about which input or state caused the failure.
|
||||
This test was written as a TDD bug-capture for #988. Both exception
|
||||
handlers in ReactiveEventBus.emit() — the per-handler block and the
|
||||
RxPY stream error block — originally omitted `exc_info=True`, so no
|
||||
traceback was forwarded to the log output when a subscriber or stream
|
||||
observer raised an exception.
|
||||
|
||||
The traceback scenario uses `@tdd_expected_fail` because that
|
||||
assertion still FAILS while the bug exists. The tag inversion
|
||||
mechanism causes CI to report that scenario as passed. Once the
|
||||
fix for #988 is merged, the `@tdd_expected_fail` tag must be
|
||||
removed so both scenarios run normally.
|
||||
Bug #988 has been fixed. The `@tdd_expected_fail` tag has been removed
|
||||
and all scenarios now run as normal regression guards.
|
||||
|
||||
See CONTRIBUTING.md > Bug Fix Workflow > TDD Issue Test Tags.
|
||||
|
||||
@@ -24,8 +21,12 @@ Feature: TDD Issue #988 — ReactiveEventBus.emit() swallows exception details
|
||||
When I emit an event that triggers the failing handler
|
||||
Then the warning log should contain the exception message text
|
||||
|
||||
@tdd_expected_fail
|
||||
Scenario: Bug #988 — emit() logs traceback via exc_info when handler raises
|
||||
Given a ReactiveEventBus with a handler that raises a ValueError
|
||||
When I emit an event that triggers the failing handler
|
||||
Then the warning log should contain traceback information
|
||||
|
||||
Scenario: Bug #988 — emit() logs traceback via exc_info when RxPY stream errors
|
||||
Given a ReactiveEventBus with a stream observer that raises a RuntimeError
|
||||
When I emit an event that triggers the stream error
|
||||
Then the warning log for the stream error should contain traceback information
|
||||
|
||||
@@ -120,6 +120,7 @@ class ReactiveEventBus:
|
||||
event_type=event.event_type.value,
|
||||
error_type=type(exc).__name__,
|
||||
error=str(exc),
|
||||
exc_info=True,
|
||||
)
|
||||
|
||||
self._audit_log.append(event.model_copy(deep=True))
|
||||
@@ -134,6 +135,7 @@ class ReactiveEventBus:
|
||||
handler=getattr(handler, "__qualname__", repr(handler)),
|
||||
error_type=type(exc).__name__,
|
||||
error=str(exc),
|
||||
exc_info=True,
|
||||
)
|
||||
|
||||
def subscribe(
|
||||
|
||||
Reference in New Issue
Block a user