Skip to content

Commit 830cbcb

Browse files
cyntwang99claude
andcommitted
fix(tasks): guarantee stream open/close pairing; tag duration by outcome
Move record_stream_opened() inside the try/finally and gate record_stream_closed on an `opened` flag, so a failure between marking the stream open and entering the try can no longer leave the active gauge permanently over-counted. Also tag the duration histogram with `outcome` (matching the closed counter) so stream lifetime can be sliced by completed / client_disconnect / error on both the OTel and StatsD paths. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
1 parent 0ea6a65 commit 830cbcb

3 files changed

Lines changed: 30 additions & 15 deletions

File tree

agentex/src/domain/use_cases/streams_use_case.py

Lines changed: 17 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -108,15 +108,20 @@ async def stream_task_events(
108108

109109
stream_topic = get_task_event_stream_topic(task_id=task_id)
110110

111-
# A stream is "open" from here on. Pair this with exactly one
112-
# record_stream_closed (in the finally below) so the active-stream gauge
113-
# stays balanced even if setup — the tail snapshot or the first yield —
114-
# raises. Placed after task resolution so a bad task_name never counts
111+
# Capture the timing/outcome state the finally needs *before* marking the
112+
# stream open, then flip ``opened`` as the first statement inside the try.
113+
# This keeps record_stream_opened paired with exactly one
114+
# record_stream_closed: the open lives inside the try, so any failure
115+
# after it still routes through the finally and rebalances the active
116+
# gauge — closing the narrow window that opening before the try left
117+
# exposed. Placed after task resolution so a bad task_name never counts
115118
# as an opened stream.
116-
record_stream_opened()
117119
stream_start_time = asyncio.get_running_loop().time()
118120
outcome: StreamOutcome = "completed"
121+
opened = False
119122
try:
123+
record_stream_opened()
124+
opened = True
120125
# Snapshot the read cursor BEFORE yielding "connected". "connected"
121126
# is the client's cue to send its message, which makes the agent
122127
# start XADD-ing deltas. Snapshotting after the yield lets a
@@ -234,10 +239,13 @@ async def stream_task_events(
234239
yield f"data: {TaskStreamErrorEventEntity(type='error', message=str(e)).model_dump_json()}\n\n"
235240
finally:
236241
logger.info(f"SSE stream for task {task_id} has ended")
237-
record_stream_closed(
238-
outcome,
239-
asyncio.get_running_loop().time() - stream_start_time,
240-
)
242+
# Only close what we actually opened, so the active gauge is never
243+
# decremented for a stream that never incremented it.
244+
if opened:
245+
record_stream_closed(
246+
outcome,
247+
asyncio.get_running_loop().time() - stream_start_time,
248+
)
241249
await self.cleanup_stream(stream_topic)
242250

243251

agentex/src/utils/stream_metrics.py

Lines changed: 8 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -133,7 +133,8 @@ def record_stream_opened() -> None:
133133
def record_stream_closed(outcome: StreamOutcome, duration_seconds: float) -> None:
134134
"""
135135
Record a task-event stream closing: bumps the closed counter (tagged by
136-
outcome), records the stream lifetime, and lowers the active gauge.
136+
outcome), records the stream lifetime (also tagged by outcome), and lowers
137+
the active gauge.
137138
138139
Args:
139140
outcome: One of "completed", "client_disconnect", "error".
@@ -148,14 +149,18 @@ def record_stream_closed(outcome: StreamOutcome, duration_seconds: float) -> Non
148149
if _closed_counter is not None:
149150
_closed_counter.add(1, {"outcome": outcome})
150151
if _duration_histogram is not None:
151-
_duration_histogram.record(duration_seconds)
152+
_duration_histogram.record(duration_seconds, {"outcome": outcome})
152153
if _active_updown is not None:
153154
_active_updown.add(-1)
154155

155156
if _STATSD_ENABLED:
156157
statsd.increment("agentex.task_stream.closed", tags=[f"outcome:{outcome}"])
157158
# Datadog histograms conventionally take milliseconds for durations.
158-
statsd.histogram("agentex.task_stream.duration", duration_seconds * 1000)
159+
statsd.histogram(
160+
"agentex.task_stream.duration",
161+
duration_seconds * 1000,
162+
tags=[f"outcome:{outcome}"],
163+
)
159164
# No StatsD "active" gauge — concurrency is OTel-only; a per-worker
160165
# DogStatsD gauge would flap rather than sum (see record_stream_opened).
161166
except Exception:

agentex/tests/unit/utils/test_stream_metrics.py

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -87,9 +87,11 @@ def test_record_stream_closed_emits_statsd_when_enabled():
8787
"agentex.task_stream.closed",
8888
tags=["outcome:client_disconnect"],
8989
)
90-
# Duration is reported to StatsD in milliseconds.
90+
# Duration is reported to StatsD in milliseconds, tagged by outcome.
9191
mock_statsd.histogram.assert_called_once_with(
92-
"agentex.task_stream.duration", 3250.0
92+
"agentex.task_stream.duration",
93+
3250.0,
94+
tags=["outcome:client_disconnect"],
9395
)
9496
# Concurrency ("active") is OTel-only, so closing emits no StatsD gauge.
9597
mock_statsd.gauge.assert_not_called()
@@ -132,7 +134,7 @@ def test_closed_records_otel_instruments_with_outcome():
132134

133135
assert opened.calls == [(1, None)]
134136
assert closed.calls == [(1, {"outcome": "error"})]
135-
assert duration.calls == [(4.0, None)]
137+
assert duration.calls == [(4.0, {"outcome": "error"})]
136138
# +1 on open, -1 on close nets to a balanced active gauge.
137139
assert active.calls == [(1, None), (-1, None)]
138140

0 commit comments

Comments
 (0)