fix(state): warn when an existing database's journal_mode is flipped to WAL - #89393
fix(state): warn when an existing database's journal_mode is flipped to WAL#89393jackulau wants to merge 1 commit into
Conversation
…to WAL apply_wal_with_fallback treats an on-disk WAL database as authoritative and says so twice: it never live-downgrades one. The mirror case had no protection at all. When the on-disk mode is DELETE and the configured mode is wal, the function flips the database and logs nothing. journal_mode is a property of the FILE, so that rewrites the header and persists after the process exits. Setting the mode directly on the file is something operators do; it was the documented mitigation for the SQLite 3.50.4 WAL-reset bug. A config key that makes the choice durable already exists (database.journal_mode, NousResearch#68545), but nothing named it at the moment the PRAGMA was being undone. NousResearch#89293 reports the cost: after upgrading past the vulnerable SQLite, is_sqlite_wal_reset_vulnerable() stopped short-circuiting into _apply_delete_for_wal_reset_bug, the flip path went live, and 4 of 5 databases silently returned to WAL with no log line anywhere. Add a deduped WARNING at both points where the switch succeeds, decided before the pragma runs since both inputs are only readable while the file is still in its original state. Log-only: the flip still happens, the return value is unchanged, and the never-live-downgrade rule is untouched. WARNING rather than ERROR is deliberate. The reverse direction is ERROR because dropping to DELETE costs concurrency; this direction is normally the desirable one (managed_uv treats a database stuck on DELETE as a bug worth repairing on update). The problem was never the change, it was that the change was invisible. The page_count guard is the load-bearing half. A brand-new database also reports journal_mode=delete and is also about to be switched to WAL, and every opener applies WAL before creating schema, so without it the warning would fire on the first run of every install. Refs NousResearch#89293
alt-glitch
added
type/bug
| _upgrading_existing_db = ( | ||
| current_mode is not None | ||
| and current_mode != "wal" | ||
| and _database_has_content(conn) |
There was a problem hiding this comment.
This is the load-bearing half. A brand-new file also reports journal_mode=delete and is about to be switched to WAL, so current_mode alone cannot tell “operator choice” from “SQLite default”. page_count is the right discriminator given every opener I checked still applies WAL before schema.
Fail-quiet on probe error (False) is the correct bias: a false warning on every fresh install would be worse than a rare missed line.
| mode = str(row[0]).strip().lower() if row and row[0] is not None else "" | ||
| if mode == "wal": | ||
| if _upgrading_existing_db: | ||
| _log_journal_mode_upgrade_once(db_label, current_mode) |
There was a problem hiding this comment.
Correct door: only after the pragma actually returns wal. The EIO-retry path later in this function has the same check, which is the other place the header rewrite can succeed.
Residual, not a request: this is still log-only. The flip has already happened by the time this fires, so a deployment that does not read the log still lands back on WAL — which is the intended policy, just worth not mistaking for a preserve-the-choice fix.
There was a problem hiding this comment.
Confirmed, and I would rather that residual be stated in the thread than inferred from the diff, so: yes, this is log-only by choice, and it is not a preserve-the-choice fix. The flip still happens, the return value is unchanged, and a deployment that never reads the log lands back on WAL exactly as it does today.
Two reasons it stops there.
The first is policy. Auto-upgrading a stuck-on-DELETE database looks deliberate rather than accidental: hermes_cli/managed_uv._default_live_venv treats DELETE as a state worth repairing on update, citing the append cost. Preventing the flip here would quietly overturn that from the storage layer, and #89293 asked for "preserve or at least warn". Warning is the half a contributor can land without making the policy call for a maintainer.
The second is that preserving the choice is not currently expressible at this call site, which I think is the more useful thing for whoever picks that up. resolve_journal_mode() returns a resolved "wal" for four different situations: the operator wrote journal_mode: wal, they wrote something invalid, the config could not be read at all (bare except Exception), or the key is simply absent. Only the last one is "nobody chose this". So a preserve-the-choice version needs config provenance (was the key present), not just its value, and then a second decision that is squarely a maintainer's: what happens to the installs that have already been flipped, whose on-disk WAL is now indistinguishable from a WAL somebody wanted.
The warning does not depend on either of those, which is why it is separable and why I kept it separable.
| "If %s was a deliberate choice (for example the mitigation for the " | ||
| "SQLite WAL-reset bug, or a WAL-unsafe filesystem), setting it with " | ||
| "PRAGMA on the file will not survive -- every open re-applies the " | ||
| "configured mode. Set `database.journal_mode: delete` in config.yaml " |
There was a problem hiding this comment.
Naming database.journal_mode is the part that makes the warning useful. File-level PRAGMA is what #89293 used as the 3.50.4 mitigation, and it cannot survive the next open; this is the lever that can.
升级前日志证据核查（回应您的问题）您好，我来确认升级前（3.50.4 时期）的日志情况。直接回答您抛回的问题——结论：WAL-reset notice 在升级前确实大量出现，而 升级前（3.50.4）实际记录到的提示日志里反复出现的是这条 WAL-reset 警告（不是 分布：
即：在 3.50.4 的保护闸下，state.db / cron/executions.db 确实被压成了 DELETE，且该警告在升级前是"看得见地"在工作的。 升级后（3.53.1）
一个您会关心的点：
|
| 指标 | 08-10 | 08-16 | 08-17(升级后) | 08-18 |
|---|---|---|---|---|
disk image is malformed |
1184 | 400 | 86 | 1 |
database is locked |
68 | 38 | 34 | 1 |
held the state.db write lock |
66 | 36 | 32 | 0 |
升级到 3.53.1 后，malformed 从 08-10 的 1184 条骤降到 08-18 的 1 条，write lock 归零。这正好支撑原报告里"WAL-reset 放大器"是问题关键一环的推断——修复放大器后锁风暴与损坏同时大幅消退。
小结：升级前的 WAL-reset 保护闸确实在可见地工作（大量 DELETE 警告），升级后闸关掉、4 个库被默认配置静默翻回 WAL，而我们从未在 config 里设置过 database.journal_mode。这条证据链支持"保留操作者选择"那一半比 warn 更有依据——我们原始诉求正是"preserve the choice, or at least warn"。
|
This is exactly the evidence I asked for, and it settles the question I threw back - thank you for going through the pre-upgrade logs properly. Three things confirmed: the WAL-reset gate was visibly working before the upgrade, But your log timeline contains something I think you passed over, and it changes what this PR should be. The DELETE mode was never anyone's choiceYou report two different messages from the same gate on
Those are two different branches of current = _on_disk_journal_mode(conn)
if current == "wal":
_log_wal_reset_bug_once(db_label, kept_wal=True) # "already in WAL — leaving WAL in place"
...
return "wal"
...
_log_wal_reset_bug_once(db_label, kept_wal=False) # "using journal_mode=DELETE instead of enabling WAL"The So the gate did not put What that something almost certainly wasYour own table dates it: Which means the causal chain runs the other way from the one in the original report: it is not "the upgrade silently reverted our journal mode". It is corruption took these databases out of WAL, the vulnerable-SQLite gate held them there and said so once per process, and the upgrade removed the gate so the default took effect again and put them back where they started on 08-01. What this means for the PRIt argues against the "preserve the choice" half of your original ask, and I think that is worth saying plainly even though it is the half you preferred. There is no operator choice on these four databases to preserve - you confirmed What is genuinely missing is the thing you asked for second: you had no way to know the mode changed. That is what this PR adds, and your data makes the case for it better than my original justification did - the flip was invisible in both directions, going in on 08-10 and coming back out on 08-17. I am leaving the scope as warn-only. One question, and one thing worth its own issueQuestion: can you confirm the 08-10 repair? Either a repair/backup line in the logs around 08-10-08-11, or a Separate issue: |
|
Follow-up filed as a separate issue: #89674 — corruption-repair silently changes a DB's journal_mode (WAL→delete) with no log record. That is the "worth its own issue" gap you flagged. I verified the 08-10 repair event from my logs: Suggested fix is at the repair site (preserve/re-apply the on-disk mode, or at minimum log it), per your steer. Linking for traceability. (Update to my earlier evidence comment: the causal chain in #89293 was backwards — it was the 08-10 corruption event, not the upgrade, that moved these stores out of WAL. Your analysis was right.) |
|
Thank you for filing #89674, and for going back and correcting your own earlier evidence comment in public - that was more than I asked for and it makes the whole chain readable for whoever picks this up. Your timeline is the part that makes the issue land: Two notes so the two threads stay in sync. #89681 already exists for it (liuhao1024, filed ~13 minutes after your issue), so it is owned. I have reviewed it rather than opening anything competing. The approach is right, but I found one thing that needs fixing before it merges and it is directly relevant to your report: the restore re-applies WAL through a helper that skips the WAL-reset vulnerability gate, so on SQLite 3.50.4 - your version at the time of the corruption - it would push the just-repaired database back into WAL, which is precisely what the gate refuses to do. Reproduced it against both code paths and posted the comparison there. Worth watching that thread if you want the fix to be safe on the runtime you actually hit this on. This PR's scope is unchanged by that. It stays the open-time warning, warn-only. The two are complementary rather than overlapping: yours flips inside repair, this one fires when an open-time upgrade moves an existing database into WAL. Neither subsumes the other, which is why splitting them was right. Nothing outstanding on this PR from my side - it is rebased on current |
4 participants
What does this PR do?
apply_wal_with_fallback()treats an on-disk WAL database as authoritative and says so twice:The mirror case has no protection at all. When the on-disk mode is DELETE and the configured mode is
wal, the function flips the database to WAL and logs nothing.journal_modeis a property of the file, so that rewrites the header and persists after the process exits.That matters because setting the mode directly on the file is a thing operators actually do — it was the documented mitigation for the SQLite 3.50.4 WAL-reset bug. There is a config key that makes the choice durable (
database.journal_mode, #68545), but nothing tells an operator it exists at the moment their PRAGMA is being undone.This adds a single deduped WARNING on that flip. It is log-only: the flip still happens, the return value is unchanged, and the never-live-downgrade rule is untouched.
Related Issue
Refs #89293
Item 1 of that report ("journal_mode silently reverted to WAL after upgrade", 4 of 5 databases) is this code path, and the reporter's own suggested remedy is what this implements:
The "after upgrade" framing is exact, and the mechanism is worth stating because it explains why this went unnoticed for so long. Before the upgrade the deployment linked SQLite 3.50.4, so
is_sqlite_wal_reset_vulnerable()was true andapply_wal_with_fallbackshort-circuited into_apply_delete_for_wal_reset_bug— which kept DELETE and never reached the flip. Upgrading to 3.53.1 turned that gate off, and the flip path went live on every database routed through this helper.response_store.dbstayed DELETE because it is the one store that does not route through it.This does not close #89293. That report is a four-part causal chain (oversized DB → cron lock storm → restart inside the lock window → WAL-reset amplifier); the other parts belong to #84277, #89088 and #88604, which the reporter already cites. This is item 1 only.
Type of Change
Changes Made
hermes_state.py_database_has_content(conn)— module-level helper,PRAGMA page_count > 0. A header read; no lock, no cost. Fail-quiet: any error answersFalse._log_journal_mode_upgrade_once(db_label, previous_mode)— mirrors the existing_log_wal_fallback_once/_log_wal_reset_bug_onceidiom (module-level set + lock, deduped per process perdb_label), with its own_journal_upgrade_warned_paths/_journal_upgrade_warned_lockpair.apply_wal_with_fallback— computes_upgrading_existing_dbbefore the pragma (both inputs are only readable while the file is still in its original state), and emits the warning at both points where the switch actually succeeds: the normal path and thedisk i/o errorretry path.Two judgment calls, stated rather than buried
WARNING, not ERROR. The reverse direction is ERROR (
_log_wal_fallback_once) because dropping to DELETE is a real loss of concurrency. This direction is normally the desirable one —managed_uv._default_live_venvtreats a database stuck on DELETE as a bug worth repairing on update, citing ~2600x slowerstate.dbappends. So the message reports a change and names the durable lever without claiming a degradation that is not there. That is also why this does not prevent the flip: preventing it would fight a deliberate design decision, and the reporter did not ask for that.The
page_countguard is the load-bearing half. A brand-new database reportsjournal_mode=delete(SQLite's default) and is about to be switched to WAL — fromcurrent_modealone that is indistinguishable from the reported bug. Every opener applies WAL before creating schema (SessionDB._connect_and_initcallsapply_wal_with_fallback, then_init_schema), so without this guard the warning would fire on the first run of every install. Four of the fourteen tests exist for this one condition.tests/test_journal_mode_upgrade_warning.py— new, 14 tests.How to Test
pytest tests/test_journal_mode_upgrade_warning.py -q # 14 passedAll behavioural — real
sqlite3on tmp files andcaplog, matchingtest_journal_mode_config.py's existing idiom (_configure_mode/_disable_vulnerable_gate). No mocking at the boundary under test.Mutation proof — every property is independently load-bearing:
page_countguard removed (treat all as existing)test_a_brand_new_database_is_silenttest_it_fires_once_per_process_per_databasedatabase.journal_modedropped from the messagetest_the_warning_names_the_setting_that_makes_it_stickdeletepathtest_configured_delete_is_silentBaseline —
pytest tests/test_journal_mode_config.py tests/test_hermes_state_wal_fallback.py tests/test_sqlite_wal_reset_gate.py tests/test_wal_checkpoint_strategy.py tests/test_conftest_wal_gate.py tests/state/ tests/test_hermes_state.py -q -p no:randomly, run serially, with and without the change:1 failed, 395 passed1 failed, 395 passedByte-identical, as a log-only change should be. The one failure is pre-existing and unrelated —
tests/test_hermes_state.py::TestFTS5Search::test_search_projection_skips_context_enrichment_queries(assert 0 == 1); it fails the same way on a clean9664e386f. The 14 new tests are additional to those counts.Overlap with open PRs
hermes_state.pyis busy and the journal-mode area especially so, so I read the neighbours rather than assuming:journal_mode=deleteis overridden by an existing on-disk WALconfigured == "delete"; this one only fires when the configured mode iswal. Theirs covers "your config lost to the file", this covers "the file lost to a default you never set" — which is the case where the operator never touched config at all. Disjoint conditions, no shared line.None/deleteso the WAL read pool is not enabled on an unconfirmed WAL_wal_activeshould be when the probe fails). Neither adds or removes a journal-mode switch.state.dbcheckpointsChecklist
Code
main)pytest tests/ -qwholesale: on Windowstests/hermes_cli/can't be collected (test_doctor_journal_modes.pycallsos.geteuid), so a full-suite number from here would be meaningless. CI runs it.Documentation & Housekeeping
database.journal_modealready exists (state.db corruption on macOS virtiofs: checkpoint_fullfsync no-ops in Linux containers; request a configurable, centralized journal_mode #68545); this change only names it in a messagePRAGMA page_countis a portable header read, and the change adds no filesystem assumptions. The macOS/NFS paths (_apply_macos_checkpoint_barrier,_enforce_macos_synchronous_full, the silent-refusal branch) are untouched and still run in the same order