fix(hass): stop log rotation killing threads that are logging at the same time - #4684
Open
romain-intel wants to merge 3 commits into
Open
fix(hass): stop log rotation killing threads that are logging at the same time#4684romain-intel wants to merge 3 commits into
romain-intel wants to merge 3 commits into
Conversation
Contributor
There was a problem hiding this comment.
🟡 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.
romain-intel
force-pushed
the
pr/log-rotation
branch
from
August 25, 2026 16:30
c6a4e7a to
3213c0d
Compare
Contributor
Author
|
Any issues with this one? I saw copilot's suggestion which seems fine to me. |
romain-intel
force-pushed
the
pr/log-rotation
branch
from
August 28, 2026 17:54
3213c0d to
3f56634
Compare
…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)
Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com>
…n join
stop_all() joins each thread with a five minute timeout and then closes the logfile unconditionally.
A thread can easily outlive that - an ML training run is tens of minutes, thirty epochs at about
half a minute each - and closing underneath one leaves it writing to a closed handle for the rest of
its life.
Seen in the field immediately after "Web interface stopped", every training epoch from then on
going to stderr:
Warn: unable to write to the Predbat logfile (I/O operation on closed file.):
ML Predictor: Epoch 1/30: ...
The write guard added earlier is what turns that into a lost log line rather than a dead thread, but
the close is the cause and it buys nothing: the process is on its way out and the OS closes every
descriptor regardless. Skip it while anything is still running, and say which threads they are so a
shutdown that leaves work behind is visible rather than silent.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
romain-intel
force-pushed
the
pr/log-rotation
branch
from
August 31, 2026 06:56
3f56634 to
ef7d01a
Compare
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
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.