Make multi-chunk logging queue-based and surface auxiliary data errors clearly - #412
Open
animmosmith wants to merge 7 commits into
Open
Conversation
animmosmith
added
bug
…s clearly Fixes #331 and #350. - process/process_realtime/merge_mfdata/process_file_list now all route logging through a multiprocessing.Queue drained by a single QueueListener, rather than each process/chunk opening its own FileHandler onto the same log file. Worker processes are named chunk-{c} so the merged log identifies which chunk each line came from. - AuxillaryData.load_auxillary_data failures are now wrapped in a new AuxillaryDataError naming the file and underlying cause, instead of being silently swallowed (or, for errors load_auxillary_data could actually raise, not caught at all). process_file_list stops the rest of that chunk on this error instead of retrying every remaining image against the same broken file. - Promoted the per-image exception traceback from DEBUG to ERROR so it's visible by default rather than only with verbose logging enabled.
…rrors process()/process_realtime() created the log queue listener before validating the config (missing output step, etc.), but only stopped it at the very end - so a validation error left the listener's background thread (and the multiprocessing.Queue feeding it) running forever. Wrap the listener's whole lifetime in try/finally so it's always stopped, regardless of where an exception occurs.
animmosmith
force-pushed
the
331-350-safer-multiprocess-logging-and-auxdata-errors
branch
from
August 5, 2026 10:08
22d0eef to
a19e6c4
Compare
…to 331-350-safer-multiprocess-logging-and-auxdata-errors
…to 331-350-safer-multiprocess-logging-and-auxdata-errors
3 tasks
…to 331-350-safer-multiprocess-logging-and-auxdata-errors
Real CI evidence: Windows CI runs on this stack were completing all tests successfully but then hanging for ~48 minutes before being killed by the 60-minute job timeout, with no further output after the test summary. Stopping the QueueListener alone isn't sufficient cleanup - the underlying multiprocessing.Queue keeps its own background feeder thread alive until explicitly closed, which per the multiprocessing docs can prevent a process from exiting cleanly. This wasn't visible in local verification (Linux/macOS) or in Ubuntu/macOS CI, but Windows' stricter process-exit/thread-cleanup semantics surfaced it as a full job timeout. Adds a shared stop_queue_logging() helper (listener.stop() + queue.close() + queue.join_thread()) used at all three call sites: process(), process_realtime(), and merge_mfdata().
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.
Summary
This PR bundles two related bug fixes, both in
pyopia.cli's logging/error handling. They're flagged separately below since they're distinct fixes for distinct issues, just sharing the same code area.Fixes #331: logging is not multiprocess-safe
pyopia process --num-chunks Npreviously had each chunk's process open its ownFileHandleronto the same log file, which isn't guaranteed safe against concurrent writes (per the Python logging cookbook linked from the issue). Every process (including the main one) now routes logging through amultiprocessing.Queuedrained by a singleQueueListener, which is the sole writer to the real log file/console. Worker processes are namedchunk-{c}so%(processName)sin the merged log identifies which chunk each line came from.Fixes #350: unhelpful error + wasted retries on a malformed auxiliary data file
A malformed auxiliary data file previously wasn't actually caught by
AuxillaryData's ownexcept RuntimeErrorclause (real parsing failures raiseKeyError/ValueError/etc., notRuntimeError), so it surfaced as a bare, unhelpful message (e.g. just'time') with no indication of the cause - and because the failedAuxillaryDatainstance was never cached,pyopia processretried the identical failure on every remaining image in the chunk.AuxillaryDataError, raised with the file path and underlying cause.process_file_listnow recognises this error specifically, logs one clear message, and stops the rest of that chunk instead of repeating the same failure per image.DEBUGtoERRORso it's visible without enabling verbose logging.Version bumped to 2.16.21, ready to merge once #394/#404/#406/#408/#410/#411 are in.
Test plan
flake8 pyopiaclean.pytest -m "not slow and not training"): 36 passed.pytest -m "slow and not training"): 19 passed.process --num-chunks 2against 4 real duplicated images withlog_fileset - single merged log file,chunk-0/chunk-1/MainProcesscorrectly tagging every line, no corruption, all 4 real STATS files produced.processagainst a deliberately malformed auxiliary CSV (headertimestampinstead oftime, reproducing the originalKeyError('time')) - error now names the file and cause, and appears exactly once (processing stopped after the first image instead of repeating for all of them).Closes #331
Closes #350
🤖 Generated with Claude Code