fix: logging None in shellcmd context causes error#4064
fix: logging None in shellcmd context causes error#4064johanneskoester merged 3 commits intomainfrom
Conversation
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Pro Run ID: 📒 Files selected for processing (1)
🚧 Files skipped from review as they are similar to previous changes (1)
📝 WalkthroughWalkthroughA bug fix that prevents TypeError crashes when logging shell commands with None messages. The fix adds defensive None/empty string checks in the logging formatter and emit paths to consistently skip empty or "None" formatted messages. Changes
Estimated code review effort🎯 2 (Simple) | ⏱️ ~12 minutes 🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ Finishing Touches
🧪 Generate unit tests (beta)
📝 Coding Plan
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. Comment |
|
lmk when this is ready |
I think now is a good time, simply added a unit test to trigger that code path, fails on main, doesn't fail here. |
There was a problem hiding this comment.
🧹 Nitpick comments (1)
tests/test_logging.py (1)
104-136: Consider adding explicit assertion and ensuring cleanup.The test correctly exercises the bug scenario, but the success condition is implicit. Additionally, if an exception occurs before
removeHandler, the handler remains attached to the global logger which could affect other tests.Suggested improvements for robustness
def test_issue4063(): # since it's difficult to replicate the exact conditions, # we'll do a unit test of the relevant logging code instead of a full workflow run. # the issue was that if the logger is configured with printshellcmds=True, # shell.py calls logger.info(None, extra={"event": LogEvent.SHELLCMD, "cmd": ...}), # which causes a crash because the default formatter expects the first argument to be a string message. from snakemake.logging import ColorizingTextHandler from snakemake.logging import DefaultFormatter from snakemake.logging import DefaultFilter handler = ColorizingTextHandler(stream=sys.stdout) formatter = DefaultFormatter(quiet=set(), show_failed_logs=False) handler.setFormatter(formatter) log_filter = DefaultFilter( quiet=set(), debug_dag=False, dryrun=False, printshellcmds=True ) handler.addFilter(log_filter) # make the logging error a hard error def handle_logging_error(record): raise sys.exc_info()[1] handler.handleError = handle_logging_error test_logger = logging.getLogger("foo") test_logger.setLevel(logging.INFO) test_logger.addHandler(handler) - test_logger.info( - None, extra={"event": LogEvent.SHELLCMD, "cmd": "echo 'bar'"} - ) - test_logger.removeHandler(handler) + try: + # This should not raise - the fix ensures None messages are handled gracefully + test_logger.info( + None, extra={"event": LogEvent.SHELLCMD, "cmd": "echo 'bar'"} + ) + finally: + test_logger.removeHandler(handler)🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@tests/test_logging.py` around lines 104 - 136, The test test_issue4063 currently relies on implicit success and may leave the ColorizingTextHandler attached if an error occurs; wrap the logging call in a try/finally inside test_issue4063 so you always call test_logger.removeHandler(handler) in the finally block, and add an explicit assertion (e.g., assert handler not in test_logger.handlers or assert no exception was raised) after the logging call to make the success condition explicit; reference the ColorizingTextHandler, DefaultFormatter, DefaultFilter, and test_logger variables when applying the change.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.
Nitpick comments:
In `@tests/test_logging.py`:
- Around line 104-136: The test test_issue4063 currently relies on implicit
success and may leave the ColorizingTextHandler attached if an error occurs;
wrap the logging call in a try/finally inside test_issue4063 so you always call
test_logger.removeHandler(handler) in the finally block, and add an explicit
assertion (e.g., assert handler not in test_logger.handlers or assert no
exception was raised) after the logging call to make the success condition
explicit; reference the ColorizingTextHandler, DefaultFormatter, DefaultFilter,
and test_logger variables when applying the change.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro
Run ID: 10b43440-2869-4c0a-974e-04b70e120b3b
📒 Files selected for processing (2)
src/snakemake/logging.pytests/test_logging.py
|
Please format your code with |
cademirch
left a comment
There was a problem hiding this comment.
thanks for fixing this
(Ideally, the logging message should also be some kind of TypedDict to be able to spot and trace such issues more easily, but that is for a later PR I'd say)
Yes I agree. Overall the logger and its interface still needs quite a bit of further refinement 😅
do we not have pre-commit hooks? gnarf |
|
Never came around to do this, but feel free to add them. |
🤖 I have created a release *beep* *boop* --- ## [9.17.0](v9.16.3...v9.17.0) (2026-03-13) ### Features * Allow storing snakemake metadata in files or databases ([#4012](#4012)) ([dd75f31](dd75f31)) * Allow to specify comparison command per-unit test ([#3956](#3956)) ([b88171c](b88171c)) * job table orderd topological when run is started ([#4018](#4018)) ([75cf506](75cf506)) * lambda functions for priority in rules ([#3253](#3253)) ([d2aa226](d2aa226)) * Make on... directive of modules accessible ([#4050](#4050)) ([e9f2e1c](e9f2e1c)) ### Bug Fixes * adjust conda tests to not fail on apple silicon; fix [#4040](#4040) ([#4049](#4049)) ([f5b0142](f5b0142)) * allow "--containerize apptainer" to output apptainer format instead of dockerfile ([#4030](#4030)) ([f5cac30](f5cac30)) * apptainer command not recognized when singularity is absent ([#4010](#4010)) ([b8162e2](b8162e2)) * capture stderr when tests fail ([#3995](#3995)) ([97d74ba](97d74ba)) * **docs:** make Data-dependent conditional execution a complete example ([#4043](#4043)) ([3a1d7f2](3a1d7f2)) * don't build the DAG when running unlock. Fixes [#4000](#4000) and [#198](#198) ([#4007](#4007)) ([acf79fd](acf79fd)) * Ensure pixi tasks may be run as advertised ([#4046](#4046)) ([88253c2](88253c2)) * fix checkpoint handling corner cases ([#3870](#3870) and [#3559](#3559)) ([#4015](#4015)) ([63f4257](63f4257)) * issue 3642 ([#4054](#4054)) ([76e6fc2](76e6fc2)) * issue 3815 ([#4026](#4026)) ([b0eec96](b0eec96)) * logging None in shellcmd context causes error ([#4064](#4064)) ([d0652cd](d0652cd)) * lookup function returns default value for empty DataFrame queries ([#4056](#4056)) ([f71de97](f71de97)) * make `cache: omit-software` a rule specific property ([#4085](#4085)) ([034a9e7](034a9e7)) * reduce number of tests leaving temporary files behind ([#4033](#4033)) ([a3a1c97](a3a1c97)) * regression in dynamic resource handling ([#4038](#4038)) ([f2c554a](f2c554a)) * somewhat shorter announce message ([#4080](#4080)) ([57efc71](57efc71)) ### Performance Improvements * switch reretry with tenacity; decouple container classes (with Python 3.7 compat for old scripts) from rest of the codebase (enabling moving to newer python versions) ([#4032](#4032)) ([ffb19e7](ffb19e7)) ### Documentation * Add AI-assisted contributions policy to contributing guidelines ([#4051](#4051)) ([dd70526](dd70526)) * **codebase:** Update & simplify plugin architecture section ([#4052](#4052)) ([176cf63](176cf63)) * Correct workflow.source_path() description in documentation ([#4036](#4036)) ([45883c5](45883c5)) * fixed wrong code example for collect() function ([#4037](#4037)) ([5c85ed8](5c85ed8)) * Minor docs improvements ([#4089](#4089)) ([29ea226](29ea226)) * switch to sphinx_design for tabs ([#3976](#3976)) ([9674614](9674614)) * typo in the migration table breaking a pip install command ([#4024](#4024)) ([66f9dda](66f9dda)) --- This PR was generated with [Release Please](https://github.com/googleapis/release-please). See [documentation](https://github.com/googleapis/release-please#release-please).
Resolves #4063
In
shell.pywe have this line:which logs with
msg=None; we can either not do that, or make the downstream logging functions deal with this better. Seems to be triggered in slurm executor contexts, not sure about local executor.(Ideally, the logging message should also be some kind of TypedDict to be able to spot and trace such issues more easily, but that is for a later PR I'd say)
QC
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).Summary by CodeRabbit
Bug Fixes
Tests