Do not wait for the flush worker while the caller holds the logging lock - #54
Merged
Merged
Conversation
…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>
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.
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 everysetLevel()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 momentdictConfig()finishes. On normal interpreter exit the interpreter has already joined the worker beforelogging.shutdown()runs, so that path is unaffected, and every other caller offlush(),logtail.rq.Workerincluded, still gets the bounded wait from #51.The first commit adds a test that reproduces the situation in-process, a caller holding
logging._lockwhile the worker's upload blocks on it, and expectsflush()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 seconddictConfig()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-levelthreading.RLockfor the whole supported range and_is_owned()is the same methodthreading.Conditionrelies on, so this is the least surprising way to ask "am I inside dictConfig".🤖 Generated with Claude Code