Skip to content

Do not wait for the flush worker while the caller holds the logging lock - #54

Merged
PetrHeinz merged 2 commits into
masterfrom
claude/flush-under-logging-lock
Sep 25, 2026
Merged

PetrHeinz merged 2 commits into
masterfrom
claude/flush-under-logging-lock

Conversation

@PetrHeinz

@PetrHeinz PetrHeinz commented Sep 25, 2026 •

Copy link
Copy Markdown
Member

0.4.2 turned the reconfiguration deadlock from #42 into a bounded stall: logging.config.dictConfig() flushes the handlers it replaces while holding the global logging lock, LogtailHandler.flush() waits for the flush worker, and the worker's upload needs that same lock whenever urllib3's logger has a level-cache miss, which every setLevel() in the new configuration causes. With the bound from #51 the Django dev server no longer hangs, but it still stops for 30 seconds at startup and the records queued at that moment are dropped.

Waiting in that situation can never succeed, so flush() now checks whether the calling thread holds the logging lock and, if it does, returns without waiting. Nothing is lost by that: the worker thread survives the handler being replaced, keeps its queue, and sends everything as soon as the caller releases the lock, which happens the moment dictConfig() finishes. On normal interpreter exit the interpreter has already joined the worker before logging.shutdown() runs, so that path is unaffected, and every other caller of flush(), logtail.rq.Worker included, still gets the bounded wait from #51.

The first commit adds a test that reproduces the situation in-process, a caller holding logging._lock while the worker's upload blocks on it, and expects flush() to return at once and the record to arrive after the lock is released; it is expected to fail CI. The second commit adds the check. On the standalone repro from the issue, the second dictConfig() now returns immediately and the queued record is delivered right after the lock is released, where 0.4.2 printed the give-up line after the timeout.

The check uses logging._lock._is_owned(). Both names are private, but the lock has been a module-level threading.RLock for the whole supported range and _is_owned() is the same method threading.Condition relies on, so this is the least surprising way to ask "am I inside dictConfig".

🤖 Generated with Claude Code

PetrHeinz and others added 2 commits September 25, 2026 15:46
…olds the logging lock

That is the situation logging.config.dictConfig() creates when it replaces an existing LogtailHandler, and the wait can only end in the timeout, since the worker's upload needs the same lock.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
@PetrHeinz
PetrHeinz marked this pull request as ready for review September 25, 2026 13:48
@PetrHeinz
PetrHeinz merged commit 1f9543f into master Sep 25, 2026
16 checks passed
@PetrHeinz
PetrHeinz deleted the claude/flush-under-logging-lock branch September 25, 2026 13:50
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant