Skip to content

bug: _cleanup() closes logger handlers before draining QueueListener, silently losing events #4136

@nh13

Description

@nh13

Bug Report

Description

In snakemake/api.py, the _cleanup() method calls cleanup_logfile() before stop():

def _cleanup(self):
    if not self.output_settings.keep_logger:
        logger_manager.cleanup_logfile()  # closes handlers first
        logger_manager.stop()             # drains queue second

This ordering creates a race condition. cleanup_logfile() iterates logfile_handlers and calls handler.close() on all handlers where writes_to_file = True, which includes logger plugin handlers. At this point, the QueueListener background thread (set up in logging.py) is still running and may still be processing queued events.

The QueueListener._monitor() loop only catches queue.Empty, so if a handler's emit() raises after the handler has been closed (e.g., writing to a closed file), the background thread crashes and any remaining queued events are silently lost.

Affected Code Paths

  • snakemake/api.py:_cleanup() (~lines 170-174)
  • snakemake/logging.py:LoggerManager.cleanup_logfile() (~lines 693-698) — closes plugin handlers
  • snakemake/logging.py:LoggerManager.stop() (~lines 722-724) — drains QueueListener

How to Reproduce

This is a race condition, so it manifests as flaky behavior. We discovered it while developing a logger plugin (snakemake-logger-plugin-snakesee) that writes events to a JSONL file. Integration tests intermittently fail on Snakemake 9.14.0 because events are lost — the plugin's file writer is closed by cleanup_logfile() while the QueueListener thread still has events to process. The race window is small, making this a flaky test failure.

Any logger plugin that writes to a file (i.e., sets writes_to_file = True) is affected.

Expected Behavior

All queued log events should be fully processed and delivered to handlers before those handlers are closed.

Suggested Fix

Reverse the call order — drain the queue first, then close handlers:

def _cleanup(self):
    if not self.output_settings.keep_logger:
        logger_manager.stop()             # drain queue first
        logger_manager.cleanup_logfile()   # then close handlers

Version Information

  • Snakemake: 9.14.0
  • Python: 3.12
  • OS: macOS / Linux

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions