Skip to content

fix(hass): stop log rotation killing threads that are logging at the same time - #4684

Open
romain-intel wants to merge 2 commits into
springfall2008:mainfrom
romain-intel:pr/log-rotation
Open

fix(hass): stop log rotation killing threads that are logging at the same time#4684
romain-intel wants to merge 2 commits into
springfall2008:mainfrom
romain-intel:pr/log-rotation

Conversation

@romain-intel

Copy link
Copy Markdown
Contributor

Rotation closed the logfile, renamed it, then opened the replacement. A component thread part-way through log() in that window wrote to a closed handle, took a ValueError all the way up and died. Nothing restarts a component thread mid-run - components.start() only runs from initialize() - so the thread stayed dead, is_all_alive() kept failing, and the dashboard reported Predbat unhealthy for the rest of the run. The load ML forecaster is the one this hit in practice, since its training thread logs steadily while the main thread is the only one allowed to rotate.

Two changes. Rotation now renames first and publishes the new handle before closing the old one: POSIX is happy to rename an open file, so a thread holding the previous reference writes into the rotated log, which is harmless. That leaves only the gap between another thread's read of self.logfile and its write, which write_log_line() absorbs by retrying once - by then the replacement is published - and then swallowing anything still failing to stderr. Logging must not be able to kill its caller, whatever the cause; a full disk should not cost a thread either.

…same time

Rotation closed the logfile, renamed it, then opened the replacement. A component thread part-way
through log() in that window wrote to a closed handle, took a ValueError all the way up and died.
Nothing restarts a component thread mid-run - components.start() only runs from initialize() - so
the thread stayed dead, is_all_alive() kept failing, and the dashboard reported Predbat unhealthy
for the rest of the run. The load ML forecaster is the one this hit in practice, since its training
thread logs steadily while the main thread is the only one allowed to rotate.

Two changes. Rotation now renames first and publishes the new handle before closing the old one:
POSIX is happy to rename an open file, so a thread holding the previous reference writes into the
rotated log, which is harmless. That leaves only the gap between another thread's read of
self.logfile and its write, which write_log_line() absorbs by retrying once - by then the
replacement is published - and then swallowing anything still failing to stderr. Logging must not
be able to kill its caller, whatever the cause; a full disk should not cost a thread either.

A lock would be the obvious fix and is the wrong one here. Pool() forks, so a lock held by a
component thread at that moment is inherited already-locked by every worker, and the first worker
to log would block forever. The existing comment ruled a lock out for a different reason - the
logfile surviving pickle - which is not what actually happens: workers reach log() through
Prediction's bound reference under fork inheritance, not pickling. The comment is corrected.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
(cherry picked from commit 5ecacb5fc573acacebbd1e4e37e8ffdd6aece12b)

Copilot AI 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.

🟡 Changes recommended

The new rotation path in hass.py still has uncaught OSError failure modes (rename/open/close) that can raise out of log() and terminate the caller thread.

Once you've addressed the issues Copilot identified, you can request another Copilot review.

Pull request overview

This PR hardens the standalone Hass logging path so logfile rotation cannot crash component threads that are logging concurrently, and adds targeted regression tests to keep that behavior stable.

Changes:

  • Introduces Hass.write_log_line() to make logfile writes resilient (retry once on rotation races, swallow persistent I/O failures to stderr).
  • Reorders rotation to publish the new logfile handle before closing the old one, reducing the likelihood of writes landing on a closed handle.
  • Adds a new unit test module and registers it in the test runner to validate rotation/write thread-safety guarantees.
File summaries
File Description
apps/predbat/hass.py Adds a non-throwing write helper and changes rotation ordering to avoid killing threads during concurrent logging.
apps/predbat/tests/test_log_rotation.py Adds deterministic tests that simulate the mid-rotation failure mode and verify retry/publish-before-close behavior.
apps/predbat/unit_test.py Registers the new log rotation tests in the unit test runner.
Review details
  • Files reviewed: 3/3 changed files
  • Comments generated: 1
  • Review effort level: Lite

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment thread apps/predbat/hass.py Outdated
Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com>
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.

3 participants