Skip to content

fix: apply SIGUSR1/SIGUSR2 log level changes outside the signal handler - #5217

Merged
connortechnology merged 1 commit into
ZoneMinder:masterfrom
nabbi:fix/b55-usr-level-signal-safe
Oct 12, 2026
Merged

connortechnology merged 1 commit into
ZoneMinder:masterfrom
nabbi:fix/b55-usr-level-signal-safe

Conversation

@nabbi

@nabbi nabbi commented Oct 12, 2026

Copy link
Copy Markdown
Contributor

Automated PR, tested in a zm-holodeck sandbox. An AI agent (Claude Opus 5.5) reproduced
the bug on a disposable ZoneMinder built from upstream master c3d2e542b with
simulated cameras, wrote this fix and ran the checks below on the same lab. Minimal
human review before opening: please review it as you would any contributor's PR.

TL;DR

  • Fixes: zmc hangs when SIGUSR1/SIGUSR2 (log level up/down) reaches a thread that is logging #5216: #: a SIGUSR1/SIGUSR2 that lands on a thread that is logging hangs the daemon.
  • Change: the handler only adds +1/-1 to a lock-free atomic; Logger::fetch(), which every log macro calls before its level check, applies it under log_mutex and logs "Level changed" from normal context; 3 files, +85/-4
  • Risk: every log call now does one relaxed atomic load in fetch(); level changes take effect at the next log call on any thread instead of inside the handler; the existing SIGUSR1 unit tests pass unchanged
  • Tested: 10 hung zmc in 3 thread-directed storms before, 0 after (7400 signals each); unit test fails before, passes after; checks covering the diff green
Details: reproduction, change, checks

Before

Upstream master c3d2e542b, clean plain build, five zmc; 3 runs of 200 rounds of SIGUSR1/SIGUSR2
sent to every thread of every zmc:

XFAIL usr-threads: 3 run(s) x 200 rounds tgkill USR1/USR2 to every thread (zmc=744 8977 15956 19241 21763 sent=7400 failed=0): 10 zmc hung in 3 run(s)
        killed 3 hung zmc (zmdc: zmc -m 2 crashed, signal 9; zmc -m 4 crashed, signal 9; zmc -m 5 crashed, signal 9)

New unit test on master's code:

/src/tests/zm_logger_rotate.cpp:143: FAILED:
  REQUIRE( slurp(path).find("Level changed") == std::string::npos )
test cases:  4 | 3 passed | 1 failed

Change

  • src/zm_logger.cpp, src/zm_logger.h: new static std::atomic<int> smLevelChange
    (static_assert lock-free). usrHandler increments/decrements it and returns, like the
    SIGWINCH branch. Logger::fetch() checks it (relaxed load) and calls the new
    applyLevelChange(): exchange(0), level(limit(mLevel + change)) under log_mutex, then
    Info("Logger - Level changed to %d %s", ...) outside the lock. initialise() resets it, so a
    change pending when logInit() replaces the logger isn't applied to the new one.
  • Test: tests/zm_logger_rotate.cpp, 2 cases: the handler writes nothing and the next log call
    logs the change before its own line; several signals add up; lowering clamps at NOLOG;
    a pending change doesn't carry over to a new logger. The first fails on master.

Behaviour changes

Change Who sees it Intended / collateral Alternatives looked into Chosen, why Tested by
The level changes at the next log call on any thread, not inside the handler admins sending SIGUSR1/2 intended apply it in logPrint like SIGWINCH: logPrint is only reached for lines at or below the current level, so raising from INFO would wait for the next Info line; in fetch() every Debug call site applies it fetch() unit tests (existing SIGUSR1 tests: raise(SIGUSR1); Debug(1, ...) still logs); live: Logger - Level changed to 1 DB1 then to 0 INF in Logs
Several signals between two log calls give one "Level changed" line with the net level log readers collateral one line per signal needs a queue from the handler net change unit test
Lowering past NOLOG or raising past DEBUG9 still clamps; a USR1/USR2 pair between log calls is a no-op (before: at DEBUG9, USR1 then USR2 gave DEBUG8) admins collateral (edge case) keep up/down counts separately: ordering between them is lost anyway net change unit test
One relaxed atomic load per log macro all daemons collateral negligible next to the call itself checks below

Side fixes in this PR: none. Not changed: mLevel/mEffectiveLevel stay plain ints read
without the lock on the hot path (ThreadSanitizer still reports that read against the write,
now made under log_mutex); making them atomic is a separate change.

Related: #5203 (logger reload, open) touches the same files; the two merge without conflicts.

After

Branch fix/b55-usr-level-signal-safe at 367e19d4f (base c3d2e542b), tested in a merge with
two other fixes from the same lab session (combo = master + this +
fix/b65-zmc-stop-during-startup + fix/b77-monitorlink-token-leak; no shared files):

"head": "69fa500a6683a16c937ae8be4d249a7eb52ba861", "branch": "combo", "dirty": false (plain)
PASS  usr-threads: 3 run(s) x 200 rounds tgkill USR1/USR2 to every thread (zmc=1318 1329 1338 1347 1357 sent=7400 failed=0): 0 zmc hung in 0 run(s) [66s]
Check Result
holodeck checks for the diff (check-changed.py: unit-tests, script-tests, smoke, resilience, events, dblog --quick, signals --quick) unit-tests ok (14725 assertions in 251 test cases), script-tests PASS=31, smoke PASS=11 XFAIL=1 (stock zmonvif-probe.pl discovery, known), resilience PASS=5, events PASS=10 (record, mocord, modect-only, nodect, monitor, linked, jpegs, reload, filters, purge), dblog --quick PASS=1 XFAIL=2 (thread-error, contention: known on master, #5197/#5208), signals --quick PASS=4 (hup-default, usr, usr-threads, startup-stop)
pyzmNg / ha-zoneminder / zmNinjaNg not run: no API, web or stream change
contract baselines (master) not run: no PHP change

Not run: the deep set. Backport to release-1.38: same bug; the commit doesn't cherry-pick
(1.38's handler has no SIGWINCH branch and no DatabaseLogPause), a hand port is a few lines (not prepared).

Tested as 389f9e5aa; 367e19d4f is the same tree with fixes #5216 added to the message.

fixes #5216

🤖 Generated with Claude Code

Logger::usrHandler changed the level and called Info() from the handler.
Info() takes log_mutex, glibc's syslog and tzset locks (syslog,
localtime_r) and the database queue's mutex, and allocates. A SIGUSR1 or
SIGUSR2 delivered to a thread already inside one of those waits on
itself, and the process hangs until zmwatch/zmdc kill it.

The handler now only adds +1/-1 to a lock-free atomic, as the SIGWINCH
branch already sets a flag. Logger::fetch(), which every log macro calls
before its level check, applies a pending change under log_mutex and logs
"Level changed" from normal context, so the new level is in effect at the
next log call on any thread. Several signals before that add up to one
change, clamped to NOLOG..DEBUG9. logInit() drops a change still pending
for the logger it replaces.

fixes ZoneMinder#5216

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

@connortechnology connortechnology left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

The diagnosis is right and the fix is sound. Flagging instead of logging matches the SIGWINCH branch, exchange(0) makes sure only one thread applies a given change, and the reset in initialise() keeps a pending change from carrying over to a new logger. Picking the change up in fetch() rather than logPrint() is the right call: it means a raise from INFO takes effect at the next Debug call site.

I built this branch locally and ran the tests (Debian, Debug build, -DBUILD_TEST_SUITE=ON). The four SIGUSR cases pass, including the two new ones. On the full ~[notCI] run, the only failures were the font and annotate tests, which load font files by relative path and fail when run from build/, so they look unrelated to this change. I did not rerun the tgkill stress test.

Two small things:

  • The PR description has a leftover placeholder: "Fixes: #5216: #:".
  • release-1.38 has the same handler (no SIGWINCH branch), so it needs the hand port mentioned in the description.

Comment thread src/zm_logger.cpp
// limit() first: level() ignores anything at or below NOOPT.
new_level = level(limit(mLevel + change));
}
Info("Logger - Level changed to %d %s", new_level, smCodes[new_level].c_str());

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Minor: this now runs on whichever thread makes the next log call. If that thread is inside a DatabaseLogPause (zmDbDo, the queue's own Warning), the "Level changed" line goes to the file and syslog but never reaches the Logs table. It can't deadlock: dbQueue.push() only takes the queue's mMutex, and Error() calls made while holding db_mutex already rely on that. I don't think this needs a change; mentioning it in case someone goes looking for that line in the Logs table.

@connortechnology
connortechnology merged commit 805a37b into ZoneMinder:master Oct 12, 2026
11 checks passed
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.

zmc hangs when SIGUSR1/SIGUSR2 (log level up/down) reaches a thread that is logging

2 participants