Skip to content

fix: re-initialise the logger in place on reload instead of deleting it - #5203

Open
nabbi wants to merge 3 commits into
ZoneMinder:masterfrom
nabbi:fix/b52-logger-reload
Open

nabbi wants to merge 3 commits into
ZoneMinder:masterfrom
nabbi:fix/b52-logger-reload

Conversation

@nabbi

@nabbi nabbi commented Oct 11, 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 821030e17, 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's SIGHUP reload frees the logger while the database queue thread is using it #5202: zmc's reload frees the logger while the database queue thread is still using it (a use-after-free that can crash zmc or corrupt memory).
  • Change: on reload, zmc and zm_rtsp_server re-initialise the existing logger in place, under its lock, instead of deleting and recreating it. 6 files, +121/-4 (84 of them a test).
  • Risk: only the two reload sites change; logInit(), logTerm(), the level fields and the SIGUSR1/2 handler are untouched. The reload still closes and reopens the log file and syslog, so its output is the same as before.
  • Tested: the same reload storm under AddressSanitizer: 269 use-after-free reports on master, 0 after (886 reloads).
Details: change, behaviour changes, checks

Before

Upstream master 821030e17, ASan build, kill -HUP to each zmc every 0.5-3 s with database debug logging:

ERROR: AddressSanitizer: heap-use-after-free ... READ of size 4 ... thread T2
    #0 in Logger::databaseLevel(int) src/zm_logger.cpp:347
    #1 in zmDbDo(...) src/zm_db.cpp:309
freed by thread T0 here:
    #1 in logTerm() src/zm_logger.cpp:587
    #2 in main src/zmc.cpp:453

Change

  • src/zm_logger.cpp, src/zm_logger.h: Logger::reinitialise() (under log_mutex: log path from the static config, syslog closed, then initialise()), and logReload(): logInit() when there is no logger yet, otherwise reinitialise().
  • src/zmc.cpp, src/zm_rtsp_server.cpp: reload with logReload() instead of logTerm(); logInit(). zm_rtsp_server has the same pattern; it is its own commit.
  • Test: tests/zm_logger_reload.cpp: reloads while four threads log; use-after-free under ASan on master, passes after.

Behaviour changes

Change Who sees it Intended / collateral Alternatives looked into Chosen, why Tested by
The logger object survives a reload; its settings are re-read in place nobody (same log output) intended make every logInit() reinitialise in place (wider change, see follow-ups) only the two reload sites reload test, storm

After

Branch at 47ac523ed (base 821030e17).

Check Result
ASan reload unit test 5/5
ASan unit suite 250 cases pass
Live reload storm, ASan stack 300 rounds, 886 reloads, 17678 debug rows: 0 ASan reports, 0 zmc exits
holodeck checks for the diff (plain build) unit 250 cases; script tests PASS=29; smoke PASS=11 XFAIL=1 (known); resilience PASS=5; events PASS=10

Not run: clients (no API change), multi-server, release-1.38 (backport prepared, not run). Touches zm_logger.* like #5197; the two merge cleanly together.

Possible follow-ups

Offered for discussion, not part of this change:

  • SIGUSR1/2 handler. It writes the level fields that logPrint reads without the lock, and logs from inside the signal handler, which takes log_mutex and the database queue's mutex. If the signal lands on a thread already holding one, that thread could deadlock. Read in the code, not reproduced. Candidate: atomic level fields, and a handler that only sets a flag, with the next log line reporting the change. Benefit: removes a data race and a possible hang. Risk: the "Level changed" line appears with the next log line instead of at once.
  • Every logInit() re-initialises in place, not just reloads. Benefit: one code path. Risk: touches every daemon's startup.

refs #5202

🤖 Generated with Claude Code

nabbi and others added 3 commits October 10, 2026 18:27
…eting it

zmc's SIGHUP reload ran logTerm(); logInit(), which deletes the Logger
and creates a new one. The dbQueue thread and the stream socket threads
keep running through the reload, and zmDbDo() holds the Logger pointer
across its query to restore the database log level afterwards, so the
reload freed the object under them (heap use-after-free under ASan).

Add logReload(), which re-initialises the existing instance under
log_mutex: syslog is closed and reopened and the log file closed, as with
a new instance, but the pointer stays valid. Only the reload calls it;
logInit() and logTerm() are unchanged.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
zm_rtsp_server reloads with logTerm(); zmLoadDBConfig(); logInit() while
its RTSP server threads keep logging, the same pattern as zmc. Use
logReload() so the Logger they hold stays valid.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Four threads log the way zmDbDo() does (fetch the Logger, change its
database level, log, restore the level) while the main thread reloads the
logger 300 times. With the reload as logTerm(); logInit(), AddressSanitizer
reports a heap-use-after-free; with logReload() the instance stays valid.

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.

Reviewed and verified with a separate AddressSanitizer build of the test suite.

  • Reproduced: with master's logger and the test changed back to logTerm(); logInit() (what zmc's reload does on master), ASan reports a heap-use-after-free. A worker's Logger::logPrint() (zm_logger.cpp:487) touches the instance logTerm() freed.
  • Fixed: with this PR the same test passes with no reports.
  • On current master: merged onto master after #5197, it merges cleanly and the full unit suite passes under ASan (250 cases).
  • Locking: reinitialise() holds the recursive log_mutex while initialise() runs. initialise() only logs a Debug line, which takes log_mutex and then the queue's mutex, and never db_mutex, so the lock order stays the same as everywhere else.
  • Other call sites: the only other runtime logTerm() calls are in the forked children that run EventStartCommand/EventEndCommand. Those are single-threaded, so they aren't affected.

One small thing in the test. Its comment and worker loop describe what zmDbDo() used to do: hold the Logger pointer across a query and set the database level to NOLOG around it. #5197 removed that. The test still exercises the bug, because the workers hold Logger::fetch() and log while the main thread reloads. But the worker could simply fetch and log, and the comment could name the threads that still log during a reload (the dbQueue thread and the stream socket threads).

release-1.38 has the same logTerm(); logInit() pair in zmc.cpp and zm_rtsp_server.cpp, so I'll backport this after merge.

Agreed on the SIGUSR1/2 handler follow-up; that's separate.

This branch has not been deployed

No deployments
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.

2 participants