T-4705 Do not ship log records emitted by the flush worker itself - #46
Merged
Merged
Conversation
…d's own log records With the handler on a DEBUG root logger, urllib3's per-request record is queued, uploaded, logged again, and so on, so flush() never returns and the interpreter cannot exit. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
…d of dropping them Records logged from a flush worker are queued as TransportFrames; a batch made solely of them is discarded rather than uploaded, so the upload's own urllib3 lines ride along with the next real batch and can never trigger an upload by themselves. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
The Django setup in the docs puts the handler on the root logger. With that logger at
DEBUG, every upload feeds the handler again: urllib3 logs each request it makes atDEBUG, that record lands in the handler's queue, the next flush uploads it, urllib3 logs that request as well, and so on. Reproduced against master with a local endpoint: a singlelogger.info()produced 9 uploads in 2 seconds, and the process never exited, because the worker drains the queue at shutdown and every drain refills it. In practicemanage.pycommands and therunserverreloader hang, while the same handler on an app logger works, since urllib3's records never reach it.The first commit adds a test that attaches the handler to a logger the uploader itself logs to and expects
flush()to return; it is expected to fail CI. The second commit madeemit()drop records logged from a flush worker thread altogether. The third commit replaces that with shipping them opportunistically:TransportFrames, a marker subclass ofdictthat msgpack packs unchangedputnever blocks, so it cannot wedge on its own full queue withdrop_extra_events=FalseSo during runtime urllib3's two lines about an upload ride along with the next batch, while at
flush()or exit, where a drain necessarily ends on a transport-only batch, they are dropped. Records from application threads are unaffected.🤖 Generated with Claude Code