Skip to content

Fix Python 3.13 "Listener already started" in multiprocessing log listener - #90

Merged
AlecThomson merged 2 commits into
masterfrom
claude/python-3.13-log-listener-n11kkw
Sep 1, 2026
Merged

AlecThomson merged 2 commits into
masterfrom
claude/python-3.13-log-listener-n11kkw

Conversation

@AlecThomson

Copy link
Copy Markdown
Owner

Summary

  • Fixes a Python 3.13-only RuntimeError: Listener already started raised on the second call to beamcon_3D.smooth_fits_cube (or beamcon_2D.smooth_fits_files) within the same process.
  • racs_tools/logging.py builds a single module-level QueueListener at import time. Both functions called log_listener.start() on entry but only called enqueue_sentinel() on exit (never stop()), and every early-return/raise path (dry-run return, validation errors, "no files found") skipped even that. This left QueueListener._thread set after the monitor thread had already exited. Python 3.11/3.12 tolerate restarting in that state; Python 3.13's QueueListener.start() raises if _thread is not None.
  • Adds a running_log_listener() context manager in racs_tools/logging.py that starts the listener and guarantees stop() runs in a finally block, then wraps the bodies of smooth_fits_cube and smooth_fits_files in it, removing the bare enqueue_sentinel() calls (calling both enqueue_sentinel() and stop() would double-sentinel the queue and silently break future runs — the fix removes the former so stop()'s own sentinel is the only one consumed).
  • This unblocks running racs-tools under Python 3.13 — e.g. flint's flint_convol --mode convol --cubes, which calls smooth_fits_cube more than once per process (a dry-run get_cube_common_beam followed by convolve_cubes), and any long-lived worker (dask, celery) that outlives the task it ran.

Follow-up (not in this PR)

The listener is still a process-wide singleton, so two concurrent smooth_* calls in the same process would still interfere with each other. A fresh (logger, listener, queue) triple per call, with the queue passed explicitly into init_worker, would remove that class of bug entirely, but is a larger change than this fix warrants.

Test plan

  • Added tests/test_logging.py:
    • test_smooth_fits_cube_twice: two dry runs of smooth_fits_cube in one process both succeed.
    • test_smooth_fits_cube_dryrun_then_real: a dry run followed by a real convolution (the order flint's CLI uses).
    • test_smooth_fits_cube_exception_then_success: an exception path (no files found) followed by a successful call.
    • test_running_log_listener_relays_records_across_calls: drives running_log_listener directly across repeated start/stop cycles and asserts worker log records still reach the handler each time (a stale sentinel from the old bug would silently break this).
    • Each test asserts log_listener._thread is None and the queue is empty after every call.
    • A guard_queue_listener_start fixture monkeypatches QueueListener.start to install Python 3.13's own guard, so these tests are meaningful (not a no-op) when run under 3.11/3.12.
  • ruff check / ruff format --check pass on the changed files.
  • Manually reproduced the original RuntimeError against the pre-fix code using the same guard, to confirm the regression tests actually exercise the bug.
  • Note: could not run the full existing test suite (test_2d.py/test_3d.py) end-to-end in this environment since MIRIAD (fits/convol binaries) isn't installed here; those failures are pre-existing environment gaps unrelated to this change.

Generated by Claude Code

beamcon_3D.smooth_fits_cube and beamcon_2D.smooth_fits_files started the
shared module-level log listener on entry but only called
enqueue_sentinel() on exit, never stop(). That leaves QueueListener._thread
set even after the monitor thread has exited, and every exit path
(dry-run return, early raises) skipped the sentinel entirely, leaving the
monitor thread running. Python 3.13's QueueListener.start() refuses to
start when _thread is not None, so a second call in the same process
raises "Listener already started"; 3.11/3.12 tolerate the stale state.

Add a running_log_listener() context manager that starts the listener and
guarantees stop() runs in a finally block, then use it to wrap both
functions' bodies so every exit path leaves the listener fully stopped.
This unblocks running racs-tools under Python 3.13 (e.g. flint's
flint_convol, which calls smooth_fits_cube more than once per process).
Review of the previous commit turned up two real defects:

Guarding stop() with a reentrancy count. Because stop() joins the monitor
thread (enqueue_sentinel() did not), nesting two running_log_listener
blocks hung forever: the inner stop() enqueued a sentinel that the outer
block's monitor consumed, so the inner join() never returned. Two
concurrent callers hit the same shape, and the reverse interleaving raised
AttributeError from self._thread.join() on <=3.12, which has no None
guard. The listener is a process-wide singleton, so nested and concurrent
blocks now share one run: the first to enter starts it, the last to leave
stops it.

Keeping one queue handler per process. init_worker added a QueueHandler
unconditionally, so with a thread executor - the default - handlers stacked
up one per worker and stayed attached (1 -> 3 -> 5 -> 7 over three calls).
That fanned each record out once per handler, and since the listener is no
longer left running between calls, those handlers kept filling the queue
with nothing consuming it: 6 copies of a single record for a logger left in
that state. Pre-existing, but only harmless while a listener ran forever.

Also adds 3.13 to the CI matrix, so the interpreter this series targets is
actually exercised, and regression tests for both defects (all three fail
against the previous commit).
@AlecThomson
AlecThomson merged commit bed7f5d into master Sep 1, 2026
7 checks passed
@AlecThomson
AlecThomson deleted the claude/python-3.13-log-listener-n11kkw branch September 1, 2026 06:37
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.

2 participants