Repository navigation
fix(utils): stop wrapper_async submitting the sync success handler twice - #41058
Conversation
🤖 Devin AI EngineerI'll be helping with this pull request! Here's what you should know: ✅ I will automatically:
Note: I can only respond to comments from users who have write access to this repository. ⚙️ Control Options:
|
|
|
Greptile SummaryThis PR prevents successful non-streaming async requests from submitting the synchronous success pipeline twice.
Confidence Score: 5/5The PR appears safe to merge; the duplicate sync callback path is removed and no outstanding findings remain. The current dispatch flow retains one synchronous success submission and one asynchronous callback enqueue per successful non-streaming async request. The regression test exercises the real hook through the real thread pool, and the annotations added since the previous review satisfy the repository requirement. Both previous threads are resolved.
|
| Filename | Overview |
|---|---|
| litellm/utils.py | Removes the duplicate synchronous success-callback submission while preserving async logging delivery. |
| tests/test_litellm/test_utils.py | Adds a concurrency-sensitive behavioral regression test and fully types its callback, executor wrapper, and queues. |
Reviews (4): Last reviewed commit: "fix(utils): stop wrapper_async submittin..." | Re-trigger Greptile
Codecov Report✅ All modified and coverable lines are covered by tests. 📢 Thoughts on this report? Let us know! |
1e0bc3d to
8d0324d
Compare
|
@greptileai please re-review 8d0324d: the regression test now runs the real logging thread pool and asserts on the configured callback |
8d0324d to
f379671
Compare
|
@greptileai please re-review f379671: same test, plus a test-quality-ok reason on the submit wrapper so the lint gate passes |
_client_async_logging_helper re-submitted logging_obj.success_handler to the executor after _dispatch_success_logging had already done so, running the same success pipeline twice per async request and racing on shared logging state. Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>
f379671 to
b86de17
Compare
|
@greptileai please re-review b86de17: the test helper parameters and queues are now fully typed |
|
bugbot run |
There was a problem hiding this comment.
✅ Bugbot reviewed your changes and found no new issues!
Comment @cursor review or bugbot run to trigger another review on this PR
Reviewed by Cursor Bugbot for commit b86de17. Configure here.
1f8bae7
into
litellm_internal_staging
TLDR
Problem this solves:
success_callbackfunctions fired twice per requestHow it solves it:
User Flow
Before: an operator with a plain
success_callbackfunction configured sees it fire twice for every requestlitellm_settings.success_callback: ["my_module.my_callback"]to the proxy config and start the proxy with--detailed_debug{"model":"gpt-5.4-mini","messages":[{"role":"user","content":"Reply with the single word: pong"}],"max_tokens":16}chatcmpl-...object and"content":"pong"Logging Details LiteLLM-Success Calllines for that one request, and their callback receives the same request twice, from two different threads at the same timeAfter: the same request drives the callback exactly once
litellm_settings.success_callback: ["my_module.my_callback"]to the proxy config and start the proxy with--detailed_debug{"model":"gpt-5.4-mini","messages":[{"role":"user","content":"Reply with the single word: pong"}],"max_tokens":16}chatcmpl-...object and"content":"pong"Logging Details LiteLLM-Success Callline for that request, and their callback receives it onceRelevant issues
Affected release
Linear ticket
Resolves LIT-6931
Pre-Submission checklist
Please complete all items before asking a LiteLLM maintainer to review your PR
uv run pytest tests/test_litellm/<your_test_file>.py -v. Leave the suites (make test-unit-*,make test-unit) to CI: it finishes in ~15 minutes where a laptop takes an hour or more@greptileaito re-request a review after pushing changes)Delays in PR merge?
If you're seeing a delay in your PR being merged, ping the LiteLLM Team on Slack (#pr-review).
Screenshots / Proof of Fix
Root cause:
wrapper_asyncends every successful async call in_dispatch_success_logging, which submitslogging_obj.success_handlerto the logging thread pool directly and also schedules_client_async_logging_helper, and that helper submitted the very samesuccess_handlera second time. Both executor threads then ran_success_handler_bodyagainst one logging object. The fix deletes the second submission from the helper; the helper now only enqueuesasync_success_handler. The diff is a 9 line removal inlitellm/utils.pyplus one regression test.Scope: this PR covers the non-streaming async path (
acompletion,aresponses,aembedding, everything that goes throughwrapper_async). Streaming completions finish their logging inCustomStreamWrapperthroughdispatch_success_handlers, a separate code path this PR does not touch. The syncwrappersubmitssuccess_handleronce and is also unchanged.Shared setup (both arms):
The same request is sent three times in each arm, then the debug log is counted. Each
Logging Details LiteLLM-Success Callline is printed once per run of the syncsuccess_handler, so the expected count is 3 (one per request).Before (b3882d8)
sha256sum litellm/utils.pyon the served checkout matchedgit show b3882d8e43:litellm/utils.py(0ee6366f...), andlitellm.__file__in the proxy environment resolved to/home/ubuntu/repos/litellm/litellm/__init__.py"content":"pong"(chatcmpl-ENx1YQI0OCMFHJUiVyvWONatDOy1Z,chatcmpl-ENx1bRIzJ09xiZRQ8cJ0zEZx8PHf2,chatcmpl-ENx1eJbI8R5drem6ltvT8JQGqOGNF)proxy_before.log:Two sync success-handler runs per request (lines 592/594 and 803/804 are back-to-back entries for a single request). The sync callback fires twice per request.
After (1e0bc3d)
sha256sum litellm/utils.pygavef6b32231..., matchinggit show 1e0bc3d38e:litellm/utils.py"content":"pong":proxy_after.log:One sync success-handler run per request. The async handler count and the spend log count are unchanged at 3, so the fix removed only the duplicate.
Regression test:
tests/test_litellm/test_utils.py::test_acompletion_runs_a_custom_logger_sync_logging_hook_exactly_onceregisters aCustomLoggerwhoselogging_hookrecords the response id and then blocks on a gate, runs oneacompletionthrough the real logging thread pool, releases the gate, waits for every submitted logging future and asserts the hook saw the response id exactly once. The gate matters becausesuccess_handlersetshas_run_loggingonly after the hooks run, so a sequential re-run would be skipped while two concurrent threads both get through, which is the same race the customer hit. On the merge base it fails 3/3 withLeft contains one more item: 'chatcmpl-...', on this branch it passes 3/3.tests/test_litellm/test_utils.py,tests/test_litellm/proxy/guardrails/test_deferred_guardrail_logging.py,tests/test_litellm/responses/test_no_duplicate_spend_logs.pyandtests/test_litellm/litellm_core_utils/test_litellm_logging.pypass together (731 passed).Taxonomy audit (A-BB) of the diff: B6 is the defect fixed (the same handler released twice). C1-C7 not applicable: every caller of
_dispatch_success_loggingstill gets exactly one sync submission, including theis_litellm_internal_call,is_completion_with_fallbacksand deferred-guardrail branches. F3: streaming is a separate path (dispatch_success_handlersinstreaming_handler.py) and is written into the scope above rather than changed. T4: the test wrapsexecutor.submitonly to collect the futures it needs to wait on; the real thread pool and the realsuccess_handlerrun, and the assertion is on the callback the user configured. T5:success_callbackis set throughmonkeypatchand restored. H2: no comments added.Type
🐛 Bug Fix
Caveats (if any)
Low
proxy-behaviorjob failed once ontests/proxy_behavior/auth/test_auth_object_prefetch.py::test_join_binds_the_membership_to_the_requested_team(object MagicMock can't be used in 'await' expression), a test this PR does not touch that also failed on PR fix(prometheus): label pre-call rate limit failures with the resolved api_provider #41059 against the same base and passes locally; it passed on rerun. Veria posted nothing on this PR, matching the other recent PRs it had no security finding on (perf(logging): skip correlation contextvar stamping when request_correlation_in_logs is off #41054 through test(auth): freeze cache clock in auth prefetch behavior tests #41060)Final Attestation
Note
Medium Risk
Touches the async success logging path used by all non-streaming async API calls; incorrect deduplication could skip sync callbacks, but the change removes redundancy while keeping the existing
_dispatch_success_loggingsubmission.Overview
Fixes duplicate sync success logging on non-streaming async calls (
acompletion, etc.) by removing a secondhandle_sync_success_callbacks_for_async_callsinvocation from_client_async_logging_helperinlitellm/utils.py.Async completions still enqueue
async_success_handlerviaGLOBAL_LOGGING_WORKER; syncsuccess_callback/CustomLoggerhooks are now submitted only from_dispatch_success_logging, so legacy callbacks and logging threads no longer run twice or race on the same logging object.Adds
test_acompletion_runs_a_custom_logger_sync_logging_hook_exactly_once, which gates a synclogging_hookand tracks logging executor futures to assert the hook sees one response id peracompletion.Reviewed by Cursor Bugbot for commit b86de17. Bugbot is set up for automated code reviews on this repo. Configure here.
Link to Devin session: https://app.devin.ai/sessions/c0c9636e652649e0865582ddb107409d
Open in Devin Desktop: https://app.devin.ai/desktop/session/c0c9636e652649e0865582ddb107409d?variant=devin
Requested by: @yassin-berriai