Skip to content

fix: close plugin handlers after draining QueueListener in LoggerManager.stop()#4137

Merged
cademirch merged 5 commits into
snakemake:mainfrom
nh13:nh13/fix-cleanup-handler-order
May 4, 2026
Merged

fix: close plugin handlers after draining QueueListener in LoggerManager.stop()#4137
cademirch merged 5 commits into
snakemake:mainfrom
nh13:nh13/fix-cleanup-handler-order

Conversation

@nh13

@nh13 nh13 commented Mar 28, 2026

Copy link
Copy Markdown
Contributor

Summary

  • Plugin handlers (managed by QueueListener) were never explicitly closed during LoggerManager.stop(), leaking file handles and potentially losing buffered data in logger plugins that write to files
  • Adds explicit close loop for plugin handlers after the queue is drained but before the logger's own handlers are cleaned up
  • Adds regression test that verifies plugin handlers are closed after stop()

Closes #4136

Test plan

  • New unit test test_stop_closes_plugin_handlers fails without the fix (RED) and passes with it (GREEN)
  • Existing logging tests pass (test_logfile, test_issue4063, test_log_events_dryrun, test_log_events, test_rule_failure)

Summary by CodeRabbit

  • Bug Fixes

    • Plugin-managed log handlers are now explicitly flushed and closed during logger shutdown to ensure no pending log records remain.
  • Tests

    • Added a regression test verifying plugin handler flush/close on shutdown and ensuring background logging threads are cleaned up to prevent leakage.

@coderabbitai

coderabbitai Bot commented Mar 28, 2026

Copy link
Copy Markdown
Contributor

No actionable comments were generated in the recent review. 🎉

ℹ️ Recent review info
⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro

Run ID: ce9e5aa9-9daf-4fcf-a8c5-f4ac84b6b994

📥 Commits

Reviewing files that changed from the base of the PR and between 0d2b556 and 220bf9c.

📒 Files selected for processing (1)
  • tests/test_logging.py
✅ Files skipped from review due to trivial changes (1)
  • tests/test_logging.py

📝 Walkthrough

Walkthrough

LoggerManager.stop() now stops the QueueListener and then explicitly flushes (exceptions ignored) and closes each plugin LogHandlerBase in self.plugin_handlers. A new test verifies plugin handlers are flushed/closed and that queued records are delivered before shutdown.

Changes

Logging stop / plugin handler shutdown

Layer / File(s) Summary
Data Shape / Config
src/snakemake/logging.py
Introduces handling of plugin-managed handlers during shutdown (uses existing self.plugin_handlers).
Core Shutdown Logic
src/snakemake/logging.py
LoggerManager.stop() now stops the QueueListener and then iterates self.plugin_handlers, calling flush() (exceptions ignored) and close() on each handler.
Test Wiring
tests/test_logging.py
Adds imports for logging.handlers and queue.Queue.
Tests
tests/test_logging.py
Adds test_stop_closes_plugin_handlers() which sets up a QueueListener with a TrackingHandler, emits a record via QueueHandler, calls LoggerManager.stop(), asserts the plugin handler was flushed/closed and received the record, and ensures the listener thread is stopped in a finally block.

Sequence Diagram(s)

sequenceDiagram
    participant Test as Test
    participant LM as LoggerManager
    participant Q as Queue
    participant QL as QueueListener
    participant PH as PluginHandler

    Test->>LM: create LoggerManager (skip_plugin_handlers=True)
    Test->>QL: start QueueListener (listening Q)
    Test->>Q: put log record (via QueueHandler)
    Test->>LM: call stop()
    LM->>QL: stop() / drain queue
    QL->>Q: read record
    QL->>PH: emit(record)
    PH->>PH: flush()
    PH->>PH: close()
    LM->>Test: return (shutdown complete)
Loading

Estimated code review effort

🎯 2 (Simple) | ⏱️ ~10 minutes

🚥 Pre-merge checks | ✅ 4 | ❌ 1

❌ Failed checks (1 warning)

Check name Status Explanation Resolution
Docstring Coverage ⚠️ Warning Docstring coverage is 42.86% which is insufficient. The required threshold is 80.00%. Write docstrings for the functions missing them to satisfy the coverage threshold.
✅ Passed checks (4 passed)
Check name Status Explanation
Title check ✅ Passed The title accurately describes the main change: explicitly closing plugin handlers after draining QueueListener in LoggerManager.stop().
Description check ✅ Passed The PR description covers the problem, solution, and test plan. All required sections from the template are addressed, including QC checklist and test verification.
Linked Issues check ✅ Passed The PR addresses the core objective from #4136: explicitly flushing and closing plugin handlers in LoggerManager.stop() to prevent resource leaks and lost events.
Out of Scope Changes check ✅ Passed All changes are directly scoped to the linked issue: modifications to LoggerManager.stop() and a regression test for plugin handler closure.

✏️ Tip: You can configure your own custom pre-merge checks in the settings.

✨ Finishing Touches
🧪 Generate unit tests (beta)
  • Create PR with unit tests

Tip

💬 Introducing Slack Agent: The best way for teams to turn conversations into code.

Slack Agent is built on CodeRabbit's deep understanding of your code, so your team can collaborate across the entire SDLC without losing context.

  • Generate code and open pull requests
  • Plan features and break down work
  • Investigate incidents and troubleshoot customer tickets together
  • Automate recurring tasks and respond to alerts with triggers
  • Summarize progress and report instantly

Built for teams:

  • Shared memory across your entire org—no repeating context
  • Per-thread sandboxes to safely plan and execute work
  • Governance built-in—scoped access, auditability, and budget controls

One agent for your entire SDLC. Right inside Slack.

👉 Get started


Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share
Review rate limit: 7/8 reviews remaining, refill in 7 minutes and 30 seconds.

Comment @coderabbitai help to get the list of available commands and usage tips.

…ger.stop()

Plugin handlers are attached to the QueueListener, not the logger itself,
so they were never explicitly closed during shutdown. This could leak file
handles and lose buffered data in logger plugins that write to files.

The fix adds an explicit close loop for plugin_handlers after the queue is
drained but before the logger's own handlers are cleaned up.

Closes snakemake#4136
@nh13 nh13 force-pushed the nh13/fix-cleanup-handler-order branch from f89fad9 to 640c58f Compare March 28, 2026 16:42
@nh13 nh13 marked this pull request as ready for review March 28, 2026 16:49
@nh13 nh13 requested a review from johanneskoester as a code owner March 28, 2026 16:49
@cademirch cademirch self-requested a review March 28, 2026 18:42

@cademirch cademirch left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for this! Looks good to me. Could you just run pixi run format?

Also, we've recently updated the PR template, please fill it in for future PRs.

@jlumpe

jlumpe commented Apr 7, 2026

Copy link
Copy Markdown
Contributor

Beat me to it. I think flush() should also be called on all loggers as well? To my knowledge close() doesn't necessarily do this. I think the builtin logging.shutdown() function flushes all handlers in a try/except block before closing them.

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 1

🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.

Inline comments:
In `@src/snakemake/logging.py`:
- Around line 746-753: The loop closing plugin handlers can stop early if
handler.close() raises and currently only flush() is wrapped; update the cleanup
in the class that iterates self.plugin_handlers to wrap both handler.flush() and
handler.close() in try/except blocks (optionally logging exceptions at DEBUG) so
every handler is attempted even on errors, mirroring logging.shutdown()
behavior—locate the code that calls handler.flush() / handler.close() on items
in self.plugin_handlers and add separate try/except around close() (and improve
the existing bare except to log.debug(...) instead of silent pass if you want
diagnostics).
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro

Run ID: b01cecea-0f97-48ee-a6ca-7027093f943f

📥 Commits

Reviewing files that changed from the base of the PR and between 640c58f and 0d2b556.

📒 Files selected for processing (2)
  • src/snakemake/logging.py
  • tests/test_logging.py
🚧 Files skipped from review as they are similar to previous changes (1)
  • tests/test_logging.py

Comment thread src/snakemake/logging.py
Comment on lines +746 to +753
# Flush and close plugin handlers managed by the QueueListener
# (not attached to the logger).
for handler in self.plugin_handlers:
try:
handler.flush()
except Exception:
pass
handler.close()

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Potential issue | 🟡 Minor

Wrap close() in try-except to ensure all handlers are cleaned up.

If handler.close() raises an exception, remaining handlers in self.plugin_handlers won't be closed, potentially leaving resource leaks. This mirrors how logging.shutdown() wraps both flush and close in exception handlers.

Additionally, the static analysis flags the bare except Exception: pass — consider logging at DEBUG level for diagnostic visibility during shutdown issues, though silently ignoring is acceptable in cleanup code.

🛡️ Proposed fix to wrap close() and optionally log flush errors
         # Flush and close plugin handlers managed by the QueueListener
         # (not attached to the logger).
         for handler in self.plugin_handlers:
             try:
                 handler.flush()
-            except Exception:
-                pass
-            handler.close()
+            except Exception:
+                pass  # Ignore flush errors during shutdown
+            try:
+                handler.close()
+            except Exception:
+                pass  # Ensure remaining handlers still get closed
🧰 Tools
🪛 Ruff (0.15.9)

[error] 751-752: try-except-pass detected, consider logging the exception

(S110)


[warning] 751-751: Do not catch blind exception: Exception

(BLE001)

🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@src/snakemake/logging.py` around lines 746 - 753, The loop closing plugin
handlers can stop early if handler.close() raises and currently only flush() is
wrapped; update the cleanup in the class that iterates self.plugin_handlers to
wrap both handler.flush() and handler.close() in try/except blocks (optionally
logging exceptions at DEBUG) so every handler is attempted even on errors,
mirroring logging.shutdown() behavior—locate the code that calls handler.flush()
/ handler.close() on items in self.plugin_handlers and add separate try/except
around close() (and improve the existing bare except to log.debug(...) instead
of silent pass if you want diagnostics).

@cademirch cademirch merged commit b2a9e69 into snakemake:main May 4, 2026
59 of 60 checks passed
johanneskoester pushed a commit that referenced this pull request May 14, 2026
🤖 I have created a release *beep* *boop*
---


##
[9.21.0](v9.20.0...v9.21.0)
(2026-05-13)


### Features

* add a function to help with prepending arguments to filenames; close
[#672](#672)
([#4090](#4090))
([14ccd1d](14ccd1d))


### Bug Fixes

* close plugin handlers after draining QueueListener in
LoggerManager.stop()
([#4137](#4137))
([b2a9e69](b2a9e69))


### Performance Improvements

* adjust default sqlite PRAGMAs, auto detect network fstype
([#4152](#4152))
([3df2d35](3df2d35))

---
This PR was generated with [Release
Please](https://github.com/googleapis/release-please). See
[documentation](https://github.com/googleapis/release-please#release-please).
cademirch added a commit that referenced this pull request Jun 11, 2026
<!--Add a description of your PR here-->

Minor addendum to #4137:

- Also flush all loggers attached to `manger.logger`, extend tests to
cover this case.
- Wrap all calls to `Handler.close()` in `try/except`.
- For non-plugin loggers (attached to `manager.logger` directly),
acquire lock before flushing/closing. Not necessary for plugin loggers
because they are all feed events through a `QueueListener` and its
thread has already been shut down.

### QC
<!-- Make sure that you can tick the boxes below. -->

* [x] The PR contains a test case for the changes or the changes are
already covered by an existing test case.
* [x] The documentation (`docs/`) is updated to reflect the changes or
this is not necessary (e.g. if the change does neither modify the
language nor the behavior or functionalities of Snakemake).
* [x] I, as a human being, have checked each line of code in this pull
request

### AI-assistance disclosure
<!--
If AI tools were involved in creating this PR, please check all boxes
that apply
below and make sure that you adhere to our AI-assisted contributions
policy:

https://github.com/snakemake/snakemake/blob/main/docs/project_info/contributing.rst
-->
I used AI assistance for:
* [ ] Code generation (e.g., when writing an implementation or fixing a
bug)
* [ ] Test/benchmark generation
* [ ] Documentation (including examples)
* [x] Research and understanding


<!-- This is an auto-generated comment: release notes by coderabbit.ai
-->
## Summary by CodeRabbit

* **Bug Fixes**
* Improved logging shutdown so all log handlers are flushed and closed
safely; failures in one handler no longer interrupt complete shutdown
and teardown is more thread-safe.

* **Tests**
* Expanded tests to verify that all log handlers are flushed, closed,
and receive expected records during shutdown.
<!-- end of auto-generated comment: release notes by coderabbit.ai -->

Co-authored-by: Jared Lumpe <jared.lumpe@cepheid.com>
Co-authored-by: Cade Mirchandani <cmirchan@ucsc.edu>
Co-authored-by: Johannes Köster <johannes.koester@tu-dortmund.de>
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.

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

3 participants