fix(state): surface failed WAL checkpoints instead of silently swallowing them - #44835
fix(state): surface failed WAL checkpoints instead of silently swallowing them#44835tangtaizong666 wants to merge 7 commits into
Conversation
|
Acknowledged — #44834 was opened first (by ~2 minutes) and takes the same overall approach, so happy to defer to the maintainers on which to keep. Noting three behavioral differences in this PR for whoever consolidates, since they affect whether the guard actually detects corruption:
#44834 additionally covers the pre-VACUUM checkpoint in |
|
Verification: LGTM ✅ Reviewed the full diff (2 files, +181/-5). Replaces silent Key improvements:
Concurrency safety: The Test coverage: 129-line test class covering: busy checkpoint (debug only), I/O error (warning + probe), unexpected error (warning), unusable DB (error), corrupt quick_check (error), checkpoint never raises, close() logging. Uses No findings. |
…wing them PRAGMA wal_checkpoint(TRUNCATE) zeroes the WAL file, but _try_wal_checkpoint caught every exception with a bare 'except Exception: pass'. When a checkpoint failed mid-operation the DB could be left inconsistent with no log trace, surfacing only later as an opaque 'disk I/O error' on the next connection (state.db, TUI session store, and holographic memory all fail at once). - log benign lock contention at debug level and retry on the next periodic checkpoint - log any other checkpoint failure at warning level, then run PRAGMA quick_check and log an error if the DB is damaged, pinning the corruption to the checkpoint that produced it - log checkpoint failures in close() instead of discarding them - fix stale 'PASSIVE' comment on _CHECKPOINT_EVERY_N_WRITES Fixes NousResearch#44795
74a200b to
a2a2c0e
Compare
…error-visibility # Conflicts: # tests/test_hermes_state.py
teknium1
left a comment
There was a problem hiding this comment.
Thanks for the focused diagnostics and for checking the quick_check(1) result rather than only whether the pragma raises. The underlying periodic checkpoint still swallows failures on current main at hermes_state.py:1266-1267, so the premise is live.
Problems
- The busy handling at
hermes_state.py:1215only runs for an exception. The checkpoint result path still inspects onlyresult[1]/result[2](hermes_state.py:1258-1265on current main), so it does not classify or log a returned busy status. Add explicit status handling and a returned-busy test. SessionDB.vacuum()retains the same silent TRUNCATE checkpoint catch athermes_state.py:6510-6513. The PR discussion correctly notes that #44834 has that hunk; consolidate it so the stated checkpoint-diagnostics goal covers the sibling path.
Suggested changes
- Inspect the checkpoint status result before declaring success, logging benign busy status at debug without probing or raising.
- Carry over the pre-VACUUM checkpoint logging change and test its non-fatal continuation.
Automated hermes-sweeper review.
| @@ -1208,8 +1215,47 @@ def _try_wal_checkpoint(self) -> None: | |||
| "WAL checkpoint: %d/%d pages checkpointed", | |||
There was a problem hiding this comment.
This only recognizes busy when execute() raises. The returned checkpoint tuple is still not status-checked before the success path; handle a returned busy status too, and add a test for that non-exception case so the documented debug behavior is covered.
What does this PR do?
SessionDB._try_wal_checkpoint()runsPRAGMA wal_checkpoint(TRUNCATE)— which zeroes the WAL file — and then swallows every failure with a bareexcept Exception: pass. When a checkpoint fails mid-operation the database can be left inconsistent with no log trace at all; the failure only surfaces later as an opaquedisk I/O erroron the next connection, at which point the TUI session store, holographic memory provider, and SessionDB all fail simultaneously and the operator has nothing to correlate it with.This PR keeps the TRUNCATE checkpoint (introduced in #39058 to bound WAL growth) but makes its failures visible and diagnosable:
database is locked/busy) is logged at debug level and skipped — this is normal under multi-process concurrency and the next periodic checkpoint (every 50 writes) retries.PRAGMA quick_check(1)probe runs immediately: if the DB is damaged, an error log pins the corruption to the checkpoint that produced it instead of leaving a mystery for the next connection attempt.close()logs its best-effort checkpoint failure at debug level instead of discarding it._execute_write()callers are unaffected.Also fixes the stale "PASSIVE" comment on
_CHECKPOINT_EVERY_N_WRITES(it has been TRUNCATE since #39058).Related Issue
Fixes #44795
Type of Change
Changes Made
hermes_state.py—_try_wal_checkpoint(): replace silentexcept Exception: passwith busy-aware logging and a post-failurequick_checkintegrity probe (new helper_probe_integrity_after_checkpoint_failure());close(): log failed close-time checkpoint; fix stalePASSIVEcomment.tests/test_hermes_state.py— newTestWalCheckpointErrorHandlingclass (7 tests) covering: busy skip stays quiet, I/O error logs warning + probes integrity, healthy DB produces no error log, unusable DB logs error, malformedquick_checkresult logs error, checkpoint never raises across exception types,close()logs failed checkpoint.How to Test
pytest tests/test_hermes_state.py::TestWalCheckpointErrorHandling -q— 7 passed.hermes_state.pyhunk and re-run: 6 of 7 fail (the seventh,test_checkpoint_never_raises, asserts an invariant that holds before and after).scripts/run_tests.sh(same per-file isolation as CI) — passes;ruff check .passes;ty check hermes_state.pyintroduces no new diagnostics vsmain(88 pre-existing before and after).Checklist
Code
fix(scope):,feat(scope):, etc.)pytest tests/ -qand all tests passDocumentation & Housekeeping
docs/, docstrings) — docstrings updatedcli-config.yaml.exampleif I added/changed config keys — N/ACONTRIBUTING.mdorAGENTS.mdif I changed architecture or workflows — N/A