Files

T

root 199baadedc docs: incident report for 2026-09-12 Core state.db recovery

- WAL-unlink root cause: interactive root hermes doctor --fix / optimize-storage under a live gateway

- store rebuilt via snapshot -> .recover -> quarantine -> install; 1,902 MB -> 1,108 MB; integrity ok

- live-sync coverage resumed and verified

2026-09-12 08:28:54 -04:00

4.7 KiB

Raw Permalink Blame History

2026-09-12 Core state.db recovery and rebuild

Status: RESOLVED — store recovered, rebuilt, and installed; gateway clean; 15-min coverage resumed. Box: Core (netcup RS 2000, 152.53.192.33) Store: /root/.hermes/state.db Precedes: 2026-09-11-core-state-db-corruption.md

Summary

The Core state store was recovered from a live snapshot and reinstalled on 2026-09-12 between 01:07 and 02:09. The live store went from 1,902 MB to 1,108 MB (794 MB reclaimed) with no loss of sessions or messages, and the gateway now runs on a clean database with no orphaned file handles.

Timeline (verified from logs and file mtimes)

Time (ET)	Event
00:53:39	Corpse-relocation dir created (task 10: moving corrupt copies out of `~/.hermes`)
00:54:50	`agent.log`: a terminal call completes
00:54:53	`state.db-wal` mtime. WAL and SHM unlinked while the gateway held them open (gateway PID 2356405)
00:54:45 → 00:55:00	`wal-monitor.py` catches it live: clean (`deleted-handles: 0`, WAL inode 261435) → fresh WAL inode 298693, SHM missing, 6 deleted handles
00:58	Live `optimize-storage` migration launched (PID 2374243), gated to wait for the 01:00 archive
01:00	`hermes-backup.sh` completes: `hermes-full-backup-2026-09-12.tar.gz` (762,955,612 B)
01:04:11	Migration exits: `optimization failed: database disk image is malformed`. No VACUUM completed, no data written
01:07:14	Live snapshot taken (2,125,131,776 B)
01:08:28	Quarantine: `state.db.malformed-backup-20260912_010832`
01:08:43	`state.db.repair-attempts.json` written
01:10:13 / 01:12:47	Recovery candidates built: `recovered-20260912.db` (1,108,819,968 B), `recovered-snapshot.db`
02:00:56	`install-0912.sh` runs
02:05:01	Second quarantine: `state.db.not-a-db-20260912_020501`
02:08:48	Gateway stopped and restarted → new PID 2414111
02:09:11	Rebuilt store installed (1,108,221,952 B)
02:09:34	Install log: `quick_check=ok integrity_check=ok`, FTS present, remaining holders: none

Verified result (2026-09-12 02:22 ET)

Gateway PID 2414111 (started 02:08:48), active, zero deleted file descriptors; every state.db* fd resolves to a real file.
PRAGMA quick_check = ok; PRAGMA integrity_check = ok.
242 sessions (unchanged) / 109,825 messages (up from the damaged on-disk view) / FTS present.
Both heavy sessions intact: 20260809_033049_d51d611b = 58,359 rows, 20260827_231946_bab48b11 = 41,790 rows.
Newest message timestamp 02:21:40 — the store is live and current.
Zero corruption-class errors in errors.log after 02:09:34.
Store size 1,902 MB → 1,108 MB. The rebuild dropped the legacy v22 FTS duplicate-data bloat, which was the measured root cause of the store bloat (index 1,199 MB for 423 MB of text) — not cron/subagent accumulation (37.6 MB of 423 MB).

Root cause of the WAL unlink at 00:54:53 — OPEN

The WAL and SHM were truly unlinked, not moved (find / -inum 261435 returned nothing; the stranded bytes were preserved as /root/db-forensics/stranded-wal-261435.bin, 18,622,432 B, magic 37 7f 06 82).

Leading hypothesis, not confirmed: an interactive root shell ran Hermes repair commands — .bash_history contains hermes doctor --fix and hermes sessions optimize-storage — at approximately 00:54:50, i.e. outside the gateway process tree. Deleting a -wal/-shm out from under a live gateway is precisely how the split-brain occurs: the gateway keeps writing into the orphaned inode while fresh readers see a stale main file.

The wal-monitor.py process died; its final log line (old PID, 6 deleted handles) is stale evidence, not current state.

Actions taken

Quarantine images (4 GB) moved out of ~/.hermes to /root/db-forensics/corpses/20260912-quarantine/ so the 01:00 backup does not swallow them again — the same class of mistake that inflated the 2026-09-11 archive to 3.35 GB.
hermes-live-sync (cron 61cd31eec51c) resumed — 15-minute coverage had been OFF since 2026-09-03 15:49:45. Next run 02:37:13. The script snapshots with sqlite3 .backup (WAL-safe), so it is safe against a live gateway.
sanctioned-pauses.json entry closed and moved to _resolved.
One-shot verification armed for 02:47: downloads the live/state.db object from S3 and runs quick_check on it. Per standing rule, verification is the downloaded object, not the job status.

Open items

Identify what actually unlinked the WAL at 00:54:53 (see hypothesis above).
state.db.repair.lock (0 bytes, 2026-09-10) is stale.
Destructive prune of session 20260809_033049_d51d611b (224 MB, ended Aug 27) — deferred by choice, no longer urgent now that the rebuild reclaimed 794 MB.

4.7 KiB Raw Permalink Blame History