fix(aws): hold on to the user-text and deferred-recycle tasks - #7052
fix(aws): hold on to the user-text and deferred-recycle tasks#7052Rehansanjay wants to merge 6 commits into
Conversation
`RealtimeSession` tracks and cancels four background tasks in `aclose()` β the recycle timer, the response task, the audio input task and the main task. Two others were created and dropped on the floor. The event loop keeps only a weak reference to a bare task, so either can be garbage collected before it finishes, and neither was cancelled when the session closed. `_send_user_text` waits on `_stream_ready` before sending. Collected there, the message is never sent and `_pending_generation_fut` is never resolved, so a `generate_reply(user_input=...)` waits forever. Surviving until after close is no better: it wakes up and sends on a stream that is gone. The tasks are now kept in a set that discards on completion, and cancelled on close. `_deferred_tool_recycle` sleeps 0.15s and then recycles the session. Collected during that sleep, the recycle never happens and the new tool set is silently never applied, even though `update_tools` returned normally. It also had no replace-in-place guard, so two quick `update_tools` calls raced two recycles against each other β which is exactly what `_start_session_recycle_timer` already avoids by cancelling the previous timer first. It now follows that same pattern.
| self._deferred_tool_recycle_task = asyncio.create_task( | ||
| self._deferred_tool_recycle(), name="RealtimeSession._deferred_tool_recycle" | ||
| ) |
There was a problem hiding this comment.
tinalenguyen
left a comment
There was a problem hiding this comment.
hi, thanks for the PR! could you address the devin comments if applicable?
Devin flagged two problems with the replace-in-place guard added here. The first is real and this PR introduced it. `_deferred_tool_recycle` debounces for 150ms and then tears the session down and brings it back; only the debounce is safe to cancel. A second `update_tools` arriving during `_graceful_session_recycle` cancelled it after `_is_sess_active` was cleared but before the streams were restarted, and the replacement task then woke, saw an inactive session and returned β leaving the session stopped. Mirroring `_start_session_recycle_timer` was wrong: that one is a bare sleep with no critical section. Cancellation is now limited to the debounce. Once a recycle is past it, an incoming update sets a pending flag instead, and the running task loops once more so the newest tool set still reaches the session. The second is a smaller one: nothing awaited the task, so a failure surfaced through asyncio's unretrieved-exception handler, which can print provider detail outside the plugin's PII-tagged logging. The exception is now retrieved and logged through the plugin logger. `CancelledError` is re-raised so cancellation still behaves normally.
|
Thanks for looking β both addressed in c71252e. Rapid tool updates strand sessions. This one was real and I introduced it. Cancellation is now limited to the debounce. Past that point an incoming update sets a pending flag and the running task loops once more, so the newest tool set still reaches the session rather than racing the teardown. Deferred failures expose provider details. Nothing awaited the task, so a failure surfaced through asyncio's unretrieved-exception handler, outside the plugin's PII-tagged logging. It is now caught and logged through the plugin logger, with Worth noting |
Two follow-ups from the review. `aclose()` returned early whenever `_is_sess_active` was clear, and treated that as "already inactive". But `_graceful_session_recycle` clears that event and only sets it again once `initialize_streams(is_restart=True)` has run, so for the length of a recycle the session reads as inactive while still owning live tasks. `aclose()` landing in that window cancelled nothing and returned, and the recycle then opened a fresh session after the caller had closed it. There is now a `_closing` flag that, unlike `_is_sess_active`, is never cleared. `aclose()` sets it first, then cancels and awaits the deferred recycle and the user-text sends before the inactive check rather than after, so a recycle in flight is torn down instead of being left to restart. `_deferred_tool_recycle` checks the flag before entering its critical section and before looping, so nothing restarts a closing session. The stale-tool-result log also interpolated `tool_use_id` into the message body, where redaction cannot reach it. It now travels in `extra` under an `lk.pii.` key, like the other customer-correlated values in this file.
|
Two more from the follow-up review, both fixed in 01f6f2b. Shutdown can restart AWS sessions β this one is real and worth spelling out. There is now a Tool identifiers bypass log redaction β |
Two more from the review, both consequences of the previous commit. `aclose()` used `_is_sess_active` as its early-return guard, but that event says nothing about whether the session was closed β a tool recycle clears it for the length of its teardown and sets it again afterwards. Cancelling the recycle could therefore land inside that window, and `aclose()` would return before closing the streams, the response task, the audio input task or the main task, leaving network resources alive after shutdown. The guard is now `_closing`, which is never cleared, so close is properly idempotent. Only the prompt-end block is conditional on the session still being live; every resource teardown after it runs either way, since an interrupted recycle leaves the active event clear while its streams are still open. `_pending_generation_fut` is also settled unconditionally now, before anything can return. Cancelling a queued user-text send raises `CancelledError`, which `_send_user_text`'s `except Exception` does not catch, so a caller of `generate_reply(user_input=...)` would otherwise wait on a future nothing would ever resolve.
|
Both fixed in 55be0d8, and both were fallout from my previous commit β worth stating plainly. Shutdown strands recycled session resources. The real mistake was using The guard is now Closed text replies never finish. @tinalenguyen β this has grown past the two-line fix it started as. Every finding has been real, but if you'd rather this PR stay narrow, I am happy to reduce it to just holding the two task references and open the |
The `_closing` guard added in the previous commit treated starting a shutdown as having finished one. If the first `aclose()` raised or was cancelled partway, every later call returned immediately and the remaining tasks and streams were never released β a regression, since before this PR there was no guard and a retry did run. Shutdown now runs as a single shared task. `_closed` is set only after cleanup actually completes, so a failed or cancelled attempt leaves it False and the next `aclose()` starts a fresh one. Concurrent callers await the same task rather than racing two teardowns, and the shield stops one caller's cancellation from aborting cleanup for everyone else. `_closing` is still set on entry, before any of that, so an in-flight recycle stops even if the cleanup task has not been scheduled yet.
|
Fixed in bdd0483 β and this one was a regression I introduced, so worth being explicit. The Shutdown now runs as a single shared task. @tinalenguyen my offer from the previous comment stands and I think it is worth taking seriously now: this started as six lines holding two task references and has become a rework of the session shutdown path. Every finding has been genuine, but the last three were all consequences of my own previous fix rather than of the original bug, and the Happy to reduce this to just the two task references and open the shutdown lifecycle work as its own PR, where it can be reviewed on its own terms. Your call β I will do whichever you prefer. |
`asyncio.shield` keeps the shared close task running when the caller awaiting it is cancelled β which is the point β but it also leaves that task with no observer. A cleanup failure after the last awaiter left was discarded silently, which is the same unretrieved-task-exception problem the rest of this PR is about. A done callback now retrieves and logs it. `_closed` still only flips after cleanup completes, so the retry path added in the previous commit still applies.
|
On the remaining open thread β the The earlier review on this series flagged the opposite problem: the prewarm failure interpolated the exception into the message body, where redaction cannot reach it. I moved it to Taken literally that leaves nowhere to put the exception, and it would put this call site out of step with the rest of the codebase: If the project does want a stricter rule for provider exceptions β a redacting formatter, or an Separately, the shielded-shutdown finding is fixed in 1f48ba7: |
There was a problem hiding this comment.
Devin Review found 1 new potential issue.
1 flag not posted on this PR by your GitHub settings β view it in Devin Review. (Configure)
| exc = task.exception() | ||
| if exc is not None: | ||
| logger.error("session shutdown failed, resources may remain open", exc_info=exc) |
There was a problem hiding this comment.
|
Duplicate shutdown logging fixed in baff2d8 β correct catch. I am going to stop making changes here pending your view on scope. Where this stands: Landed and confirmed resolved β the recycle cancellation during teardown, task cleanup bypassed by the inactive early-return, shutdown reopening the session, retries blocked after a failed close, the shielded close swallowing its own failure, the duplicate log, and the PII-tagged Still open, and I do not intend to change it without your say-so: the The wider point I raised before still stands. This began as six lines holding two task references, and the last four commits have all been fixing consequences of my own previous fix rather than the original bug. The |
The bug
RealtimeSessionalready tracks and cancels four background tasks inaclose()β_session_recycle_task,_response_task,_audio_input_taskand_main_atask. Two others are created and discarded. The event loop keeps only a weak reference to a bare task, so each can be garbage collected before it finishes, and neither is cancelled when the session closes._send_user_textself._pending_generation_fut = futis set just above, then the task is dropped. If it is collected while waiting on_stream_ready, the message is never sent and the future is never resolved β agenerate_reply(user_input=...)waits forever.Surviving past close is no better: nothing cancels it, so it can wake after
aclose()and send on a stream that is gone._deferred_tool_recycleIt sleeps 0.15s, then recycles the session so the new tool set is sent in the next prompt block. Collected during that sleep, the recycle never happens and the new tools are silently never applied β
update_tools()returned normally, and the logs even say the recycle was scheduled.It also had no replace-in-place guard, so two quick
update_tools()calls race two recycles against each other._start_session_recycle_timeralready avoids exactly this:The fix
_send_user_texttasks go into a set that discards on completion, and are cancelled inaclose()._deferred_tool_recycleis stored and follows_start_session_recycle_timer's replace-in-place pattern, and is cancelled inaclose().Both cancellations sit next to the recycle-timer cancellation already in
aclose(), and append to the sametaskslist that is gathered at the end.No behaviour change on the success path.
Checks
ruff checkandruff format --checkpass on the changed file.Note: this does not touch
_session_recycle_taskor_start_session_recycle_timer, so it should not conflict with #6281.Found with a small AST pass looking for
create_taskcalls whose result is discarded β same sweep as #7050 and #7051.