Files
itpp-infrastructure/docs/incidents/2026-09-11-core-state-db-corruption.md

10 KiB

Incident: Core Hermes Store Corruption (not-a-database) and Recovery

Date: September 11, 2026 Severity: High. Core's agent lost its conversation store mid-day, which disabled session_search, delegate_task, and every cron job that reads history. Status: Recovered. Repair staged and verified, installed the same evening. Root cause: The SQLite store was written while it was being checkpointed, so the file header was destroyed. The store stopped being a database at all. Amplifier: A 1.9 GB store that had never been pruned, failing three times in three days, with backups that faithfully captured the corruption because they tarred the live file.

Ground truth for this report was re-verified at 17:45 EDT on September 11, 2026. Numbers below are from the live box, not from a summary.


1. What happened

At 12:49:22 EDT the default profile store /root/.hermes/state.db took its last write. Five seconds later the gateway restarted and found the store unreadable. Every tool that depends on history began failing with file is not a database:

session_search -> {"success": false, "error": "Session database not available: DatabaseError: file is not a database."}
delegate_task  -> Error executing tool: ... file is not a database

The file is 1,984,344,064 bytes. Its first bytes are not SQLite format 3, so SQLite rejects it before reading a single page. It is not a marginally damaged database, it is a file that no longer has a database header.

2. Impact

  • Capability loss: session_search and delegate_task were down for the rest of the day. Delegation is a load-bearing part of how this box operates.
  • Cron surface: any job reading history was at risk. The daily backup monitor kept failing for eight days, though that turned out to be a separate, already identified cause (section 6).
  • Data loss window: 11:49 to 12:49 EDT. No readable copy of that hour exists anywhere. Anything learned in that window is only recoverable from durable artifacts (DR issue log, CHANGELOG, skills).
  • Backup lineage contamination: the Sep 10 and Sep 11 archives captured the live, corrupt file. A restore from the newest archive would have restored the corruption. This is the single most dangerous detail in the incident.

3. Timeline (all times EDT)

When Event
Sep 9 WAL damage appears in the live store. First corruption event.
Sep 10 12:18 A backup is written that is already malformed.
Sep 10 12:20 A repair attempt fails.
Sep 10 14:48 A corrupt copy is preserved (state.db.corrupt-20260910).
Sep 9 to 11 Daily archives grow 1.76 GB to 2.34 GB to 3.52 GB. The growth is the unpruned store plus quarantine artifacts.
Sep 11 01:00 Nightly archive taken. This copy turns out to be clean: 1,939,980,288 B, quick_check ok, 107,588 messages, max id 321,545.
Sep 11 11:49 A snapshot is taken that is valid SQLite (1.96 GB) but has one bad page. It carries roughly 985 messages the 01:00 archive does not.
Sep 11 12:49:22 Last write to the live store.
Sep 11 12:49:27 Gateway restarts and cannot open the store.
Sep 11 16:33 Grafted candidate built and verified (state.working.db).
Sep 11 16:51 Install path hardened (chmod +x, explicit /bin/bash, dry run passed).
Sep 11 18:56 Repair scheduled to install via detached root crontab one shot.

4. Root cause

Proximate cause: a write that overlapped WAL checkpointing during the 12:49 shutdown. The store's header was overwritten, leaving an 1.85 GiB file with no valid database header. There is no evidence of filesystem damage; other files on the same volume are intact and the disk reports no errors.

What it was NOT, checked and excluded:

  • Not OOM. The box had headroom. At the time of this report Core runs 15 GB total with 4 GB used and 11 GB available, 366 GB free disk.
  • Not a cron job touching the database. No scheduled job writes to state.db directly. The 15 minute hermes-live-sync job uses .backup snapshots and excludes live files, and it had been paused since Sep 3.
  • Not a bad restore. Nothing replaced the store on Sep 11 before the 12:49 failure.

What is still unknown, and stays unknown until proven: which process requested the 12:49 gateway restart. The store was written and then the gateway came back and found it broken, and the caller was not recorded anywhere durable. That gap is itself a finding (section 7, item 5).

Why it was able to hurt this much: the store is 1.9 GB and has never been pruned. Every checkpoint, backup, and recovery operation on a store that size is slow, IO heavy, and exposed to exactly this failure mode. Three corruption events in three days (Sep 9, 10, 11) is not bad luck, it is a store operating outside safe limits. The corrupt copy from Sep 3 through Sep 10 in Anita's frozen profile shows the same pattern on a second profile, which points at the host and the store size rather than at one profile's content.

5. Recovery

Strategy: do not try to repair the corrupt file body. Build a new store from the newest clean copy and graft forward the messages that only exist in newer ones.

  1. Base: the 01:00 archive store, verified clean: quick_check ok, 107,588 messages, max id 321,545.
  2. Graft: 985 messages from the 11:49 snapshot (valid SQLite, one bad page) into the base. Grafting is row by row, so a single unreadable page costs a row, not the migration.
  3. Result: /root/db-forensics/state.working.db, 1,961,385,984 B, verified at 17:45 EDT:
PRAGMA quick_check     -> ok
PRAGMA integrity_check -> ok
108,573 messages / max id 322,530 / 242 sessions
FTS intact: messages_fts and messages_fts_trigram with all supporting tables

985 grafted rows against 107,588 base rows reconciles exactly to 108,573.

Install path: the job runs as a detached root crontab one shot writing to /root/db-forensics/cron-invoke.log, not systemd-run and not /etc/cron.d (both blocked by the lifecycle guard on this box).

First attempt failed for a boring reason worth recording: install.sh was not executable, so cron forked it and it died within a second, writing nothing anywhere. The fix is three parts: chmod +x, invoke explicitly as /bin/bash <script>, and log stdout and stderr to a file that can be read afterwards. It was then exercised in --dry-run before being armed for real.

6. Side finding: the backup monitor was crying wolf for eight days

Backup-Health-Monitor (daily 09:00) had failure_streak=8 and last_status=error.

  • The one real CRITICAL was hermes-live-sync: DISABLED/PAUSED (job 61cd31eec51c, paused 2026-09-03 15:49, the same window as the first corruption event). The script exits 1 only when total_critical > 0, never for warnings, so that single pause accounts for the entire streak.
  • Its three WARNINGs are false positives, proven by content rather than by size:
    • Wazuh Manager (app1): the tarballs for Sep 9, 10 and 11 are all sha256 0e65a2364cdc0795..., identical. The content is a static config, and the 03:15 job did run today. Not stalled.
    • LiteLLM Config (app1): the flagged object is a 333 byte config yaml that legitimately never changes. The actual data backup is app1/litellm/litellm-backup-*.tar.gz, 47 of them, newest 37,894,223 bytes at 03:30 today, and it carries the Postgres dump.
    • MySQL voipsimplicity (app3): identical size 6,834,636 bytes each day but a different sha256 each day (cb1ce9f8, 92c5eb70, b83ea28f), valid gzip, 73 tables, real mysqldump 8.4.10. Content is changing, the size simply coincides.
  • Conclusion: the size uniqueness heuristic cannot tell "static but fine" from "stalled". Those three checks should be reclassified as "unchanged content" rather than SUSPICIOUS. Not yet changed.

7. Prevention

  1. Prune the store. 1.9 GB unpruned is the amplifier behind all three failures. Needs a retention policy and a size cap, sized before anything is deleted (session count, cron and watcher noise measured first).
  2. Snapshot, never tar, live databases. Excluding *.db from the essentials archive is correct. What was missing was the replacement, now supplied by hermes-db-backup.sh, which takes a sqlite3 .backup per database, quick_check each snapshot, uploads, then downloads and re-verifies. Deployed on the Anita box with cron 10 3 * * *, proven by round trip (291 MB snapshot, quick_check ok, 99,285 messages).
  3. Never trust a backup that has not been restored. Every archive is now suspect until an object has been downloaded, extracted, and opened. The Sep 10 and Sep 11 archives would both have restored the corruption.
  4. Check integrity on the newest snapshot daily, not just its existence and size. PRAGMA quick_check on the newest object is cheap and would have caught the Sep 10 and Sep 11 contamination on the day it happened.
  5. Record who restarts the gateway. The 12:49 caller is still unknown. The restart path should write caller identity, reason, and timestamp to a durable log so this question is answerable next time.
  6. Resume the 15 minute checkpoint only after the repaired store verifies healthy, and prove the resumed job by downloading its object and running quick_check on it.
  7. Keep quarantine artifacts for a retention window. The only unique bytes in the deleted frozen profile were the Sep 3, 9 and 10 quarantine files. They are archived, not discarded, so a future investigator can compare failure signatures.

8. Evidence (re-verified 2026-09-11 17:45 EDT)

live      /root/.hermes/state.db                      1,984,344,064 B   mtime 2026-09-11 12:49:22   header: NOT SQLite
donor     /root/sqlite_tmp/sep11/hermes-backup-2026-09-11/state.db
                                                      1,939,980,288 B   quick_check ok  107,588 msgs  max id 321,545
candidate /root/db-forensics/state.working.db         1,961,385,984 B   quick_check ok  integrity_check ok
                                                                       108,573 msgs  max id 322,530  242 sessions
disk      503 GB volume, 117 GB used, 366 GB free
memory    15 GB total, 4 GB used, 11 GB available

9. Lesson

The failure was survivable because the 01:00 archive happened to be clean and the 11:49 snapshot happened to be readable enough to graft from. That is luck, not architecture. Two things made it luck: backups that copied the live store, and no pruning on a store big enough that every operation on it is a window of risk. Both are fixed or scheduled. The remaining exposure is the same store size, which stays live until a retention policy is agreed.