Repository navigation
Add logging to safe_run command execution - #16
Conversation
There was a problem hiding this comment.
Scope looks right — one file, logging only, no change to CommandResult values or control flow — and I confirmed no caller passes credentials in cmd, so the new cmd_str logging doesn't leak secrets (stderr is debug-only, which is the right call). One blocking issue though.
utils.py:41-42 — WARNING on any non-zero exit misreports this codebase's normal operation.
setup_logging() defaults to INFO and streams to stderr, so these warnings print during every ordinary scan, interleaved with the print() progress output in __main__.py. But non-zero exit is a designed signal for most safe_run callers, not a failure:
scanners/patches.py:123-125—dnf check-update -qreturns 100 when updates are available; that's the finding-producing path, and the code comment says so. It'll now logCommand failed with return code 100.scanners/antivirus.py:70,74andscanners/services.py:165,scanners/audit_logging.py:80,191—systemctl is-active <unit>returns 3 when the unit is inactive, which is exactly what the check is probing for.scanners/antivirus.py:80—pgrep -x clamdreturns 1 on no match.scanners/firewall.py:115—firewall-cmd --statereturns 252 when firewalld isn't running, handled viaif not result.success: return False.scanners/users.py:410—dscl . -read /Users/Guestfails when there is no Guest account, i.e. the secure state gets a warning.scanners/software.py:508-512—npm audit --jsonexplicitly treatsreturncode > 0as valid (if audit_result.success or audit_result.returncode > 0).
Net effect: a correctly configured machine produces a stream of scary Command failed warnings for expected outcomes, which makes the real failures this PR is trying to surface harder to spot, not easier. Please either demote line 42 to logger.debug (the stderr line below it is already debug), or add an opt-in parameter — e.g. expected_returncodes: tuple[int, ...] = (0,) — and only warn when the code falls outside it, so call sites like dnf check-update can declare 100 as normal.
Same concern, smaller, for utils.py:54: FileNotFoundError is ERROR, but several call sites intentionally probe for tools that may not be installed without a has_command() guard (scanners/passwords.py:407 pwpolicy, scanners/users.py:418 dscl). "Tool not present on this platform" reads better as debug/info.
Non-blocking nits while you're in there:
utils.py:28— every other module in the package uses a module-levellogger = logging.getLogger(__name__); re-fetching it per call deviates from that convention for no benefit.utils.py:31— trailing whitespace on the blank line.- Lines 30/42/44/51/54/57 use f-strings; the repo mostly uses lazy
%sformatting (e.g.__main__.py:160), which avoids building the message when the level is disabled — relevant for the per-call debug line here.
…rnings/errors Many callers treat a non-zero return code as a normal result (dnf check-update=100, systemctl is-active=3, npm audit, pgrep, etc.) and some intentionally probe for binaries that may not exist (pwpolicy, dscl). Demote those cases to logger.debug instead of warning/error so real failures aren't buried in noise during ordinary scans. Also switch to a module-level logger, lazy %s formatting, and drop trailing whitespace to match the rest of the package. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
|
Verified all the reviewer's points against the actual call sites and they held up — fixed everything raised. Fixed:
Skipped the "opt-in Added Checks: |
There was a problem hiding this comment.
All blocking feedback from the previous round is addressed: non-zero exits (utils.py:42-48) and FileNotFoundError (utils.py:57-61) are now debug, so the designed non-zero signals in this codebase — dnf check-update 100, systemctl is-active 3, pgrep 1, firewall-cmd --state 252, npm audit >0 — no longer print spurious warnings on a correctly configured machine; the logger is module-level and all call sites use lazy %s formatting. ERROR is reserved for timeout and the generic except Exception (with exc_info), which are the real swallowed failures this PR set out to surface, and no caller inspects timed_out so that is the only visibility into them.
Checked that return values and control flow are unchanged (logging only, no CommandResult field touched), and that cmd_str = " ".join(cmd) is safe for every caller — I grepped the safe_run call sites and all arguments are strings, and none passes a credential; the credential-related callers (credential_exposure.py:481,544,577, hardeners/passwords.py:191-224) only pass registry paths and policy key=value literals, so the ERROR-level cmd_str lines leak nothing. Scope is two files, 45 added lines, nothing unrelated bundled in; the new tests/test_utils.py pins exactly the regression that was fixed.
What
Add debug and error logging to safe_run() to expose silent failures and command execution details.
Why
Command execution failures can be difficult to debug without visibility into what commands are running and why they fail.