Make debug.log rotation multiprocess-safe via concurrent-log-handler - #1442
Merged
Conversation
…1439) Gunicorn runs 3 workers on -test and prod, each opening the same media/debug.log through LOGGING['handlers']['file']. The stdlib RotatingFileHandler is not multiprocess-safe: when one worker rotated, the others kept writing to the renamed inode and then rotated the nearly-empty new file themselves, so backups truncated far below maxBytes and log records were silently lost (see #1439 for the prod evidence). Swap the handler class for concurrent_log_handler. ConcurrentRotatingFileHandler (new pinned dependency), which takes a cross-process file lock around every write and rollover. Its lock file is redirected to /tmp rather than its default location next to the log, because LOG_FILE lives inside the web-served media root; /tmp is shared by all workers since they run in one container. The #1283 NullHandler degrade path is unchanged. Tests pin the new handler class, assert the lock dir stays out of MEDIA_ROOT, and build the real handler via dictConfig to guard the class path and kwargs (a typo'd kwarg would crash django.setup() on every server). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Five follow-ups from the review of PR #1442, all in the same area: 1. The handler class was a hard dependency: dictConfig raises ValueError on an unimportable class, aborting django.setup() with none of the #1283 degrade signals. That state is reachable without a broken deploy -- the container bind-mounts the checkout over /code while site-packages come from the last image build, so a branch switch (or the gap between the deploy webhook's git pull and its build) can run this settings.py against an older image. Probe the import once and fall back to the stdlib RotatingFileHandler: racy on rollover, but logging keeps working. 2. Nothing validated the lock directory. gettempdir() itself can raise, and a lock file that can't be opened fails inside emit() -> handleError (stderr, unread on the servers) while /version.json still says healthy. Resolve and writability-check the dir up front; degrade if unusable. 3. The lock path was a fixed name in a world-writable sticky dir (/tmp/.__debug.lock, opened "r+"). A root-created one -- the devcontainer connects as root -- locks the apache workers out permanently, since /tmp's sticky bit stops them unlinking it. Namespace the dir by uid, so a lock is only ever shared with same-uid processes (the deployed case). 4. The instantiation test's dictConfig closed every handler Django had configured, for the rest of the test process. Re-apply settings.LOGGING. 5. django.db.backends emitted a record per SQL query on -test (DEBUG=True) -- the bulk of the volume behind the rapid rollovers, now also the biggest payer of the per-record cross-process lock, and raw SQL in a publicly downloadable file. Pinned to INFO. Degrading quietly is the thing #1283 exists to prevent, so the resulting handler is reported as log_rotation on /version.json (derived from the built LOGGING dict so it can't drift) and printed as a startup warning. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…otation-race # Conflicts: # CLAUDE.md # makeabilitylab/settings.py
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
1 participant
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.
Fixes #1439.
Problem
Gunicorn runs 3 workers on -test and prod (
docker-entrypoint.sh), each building its ownRotatingFileHandlerover the samemedia/debug.log. The stdlib handler is not multiprocess-safe: workers raced on rollover, renaming each other's freshly created files, so backups truncated far belowmaxBytes(11 KB files against a 5 MB threshold) and log records were silently lost. Full evidence and mechanism in #1439.Fix (option 1 from the issue)
requirements.txt— addconcurrent-log-handler==0.9.29(sole transitive dep:portalocker). Purpose-built drop-in that takes a cross-process file lock around every write and rollover.makeabilitylab/settings.py—_file_log_handlernow returnsconcurrent_log_handler.ConcurrentRotatingFileHandlerwith the samemaxBytes/backupCount. Its lock file is redirected to/tmpvialock_file_directory— the default drops it next to the log, i.e. inside the web-served media root./tmpis container-local, which is correct: all 3 workers share one container. The settings.py hardcodes the log file to /code/media/debug.log (breaks on any host without that path) #1283 NullHandler degrade path is untouched.website/tests/test_logging_config.py— pins the new handler class; asserts the lock dir stays outsideMEDIA_ROOT; and builds the real handler vialogging.config.dictConfig, writes a record, and verifies no lock file lands beside the log — guarding the class path and constructor kwargs (a typo'd kwarg would crashdjango.setup()on every server).settings_test.pyand CLAUDE.md.Testing
Full suite (726 tests) run in a one-off container against the running local stack with the new package installed: OK (8 pre-existing skips). The dictConfig test exercises the real 0.9.29 package, confirming
lock_file_directoryis a valid kwarg.After deploy to -test, verify by checking that
debug.log.Nbackups only ever appear at ~5 MB and that/version.jsonstill reportslog_to_file: true.🤖 Generated with Claude Code