Recovery after a password reset restores the note as an empty file #15

Closed
opened 2026-09-15 11:16:43 +01:00 by cruelacid · 2 comments
Owner

recovery.test.ts has been failing on main since the nightly of 14 September, and it is the one e2e scenario about not losing someone's writing.

The scenario. A person forgets their password, resets it, and opens a fresh vault. A note they wrote before the reset should come back from recovered material.

What happens instead. The note arrives as an empty file, and the client concludes it is already correct. From the plugin's own diagnostic log in the recovered vault:

Meta listed a file {"key":"before-the-reset.md","existsLocally":false}
Create accepted {"path":"Shared/before-the-reset.md", ...}
Document bound {"path":"Shared/before-the-reset.md","idbBytes":0,"alreadySynced":false}
Reconciliation decision {"hasUnsentWork":false,"lastSeq":1,"catchUpFrames":1}
Synced content already on disk {"path":"Shared/before-the-reset.md","bytes":0,"hasSyncedOnce":true}

The file is created, bound, reconciled against a single frame, and then declared settled at zero bytes. The test waits sixty seconds and reports the vault contains Shared/before-the-reset.md whose content is "".

This is the shape of failure CLAUDE.md singles out: "An empty document might mean 'empty' or 'not heard from yet', and those are different." The client cannot tell the two apart here and picks the one that discards the writing, and Synced content already on disk means nothing warns anybody.

When it started. The nightly was green on 13 September and red on 14, 15 and 15 September. Twenty-one commits landed in that window; none obviously touches the recovery path, and several touch keys, devices and sessions (7978815 keeps one live session per install, d461954 adds organisation creation). Bisecting the nightly window is the obvious next step.

Why it went unnoticed for three nights. The e2e suite ran nightly and nothing read the result. That is exactly what CD phase 3 (#13) changes: it makes this suite the gate a build must pass before it can be promoted to :stable.

It therefore blocks #13. The gate is written and its build half is green on cd-phase-3, but merging it cannot switch anything on while the suite it gates on is red — correctly, because a red gate promotes nothing. Both hosts are safe meanwhile: AUTO_DEPLOY=off, both on 23db287.

Reproduce locally with pnpm --filter @nectenda/e2e test:e2e:multi; it is the only failing file, 1 failed and 56 passed.

`recovery.test.ts` has been failing on `main` since the nightly of 14 September, and it is the one e2e scenario about not losing someone's writing. **The scenario.** A person forgets their password, resets it, and opens a fresh vault. A note they wrote *before* the reset should come back from recovered material. **What happens instead.** The note arrives as an empty file, and the client concludes it is already correct. From the plugin's own diagnostic log in the recovered vault: ``` Meta listed a file {"key":"before-the-reset.md","existsLocally":false} Create accepted {"path":"Shared/before-the-reset.md", ...} Document bound {"path":"Shared/before-the-reset.md","idbBytes":0,"alreadySynced":false} Reconciliation decision {"hasUnsentWork":false,"lastSeq":1,"catchUpFrames":1} Synced content already on disk {"path":"Shared/before-the-reset.md","bytes":0,"hasSyncedOnce":true} ``` The file is created, bound, reconciled against a single frame, and then declared settled at zero bytes. The test waits sixty seconds and reports the vault contains `Shared/before-the-reset.md` whose content is `""`. This is the shape of failure `CLAUDE.md` singles out: *"An empty document might mean 'empty' or 'not heard from yet', and those are different."* The client cannot tell the two apart here and picks the one that discards the writing, and `Synced content already on disk` means nothing warns anybody. **When it started.** The nightly was green on 13 September and red on 14, 15 and 15 September. Twenty-one commits landed in that window; none obviously touches the recovery path, and several touch keys, devices and sessions (`7978815` keeps one live session per install, `d461954` adds organisation creation). Bisecting the nightly window is the obvious next step. **Why it went unnoticed for three nights.** The e2e suite ran nightly and nothing read the result. That is exactly what CD phase 3 (#13) changes: it makes this suite the gate a build must pass before it can be promoted to `:stable`. **It therefore blocks #13.** The gate is written and its build half is green on `cd-phase-3`, but merging it cannot switch anything on while the suite it gates on is red — correctly, because a red gate promotes nothing. Both hosts are safe meanwhile: `AUTO_DEPLOY=off`, both on `23db287`. Reproduce locally with `pnpm --filter @nectenda/e2e test:e2e:multi`; it is the only failing file, 1 failed and 56 passed.
Author
Owner

Not closed. Here is what the evidence actually says, so the next run does not repeat the dead ends.

The bisect is void — the test is flaky, not newly broken. git bisect blamed 35360f5 ("Use Obsidian's own grouped-list markup"), a settings-pane commit. Checking that verdict rather than accepting it: at 35360f5 the scenario passes twice and fails once, and at its parent it passes three times out of three. A one-run-per-step bisect against a test that fails roughly one run in three will blame an arbitrary commit. So the window 13→14 September is where the failure rate crossed the threshold of being noticed, not where a regression landed. Treat recovery.test.ts as long-standing and intermittent.

It is worse than a reader failing to receive. The writer's own vault destroys the note. From diag-A.log on a failing run:

11:01:33.403  Computed the delta the server is missing {docName: 4b1dbbef…, deltaBytes: 2, willPush: false}
11:01:33.904  Synced content already on disk {path: before-the-reset.md, bytes: 42, hasSyncedOnce: true}
11:01:34.986  Writing synced content to disk {path: before-the-reset.md, diskBytes: 42, docBytes: 0}

The document holds the 42 bytes at 33.904 and is empty at 34.986, and the empty document is then written over the file. No conflict copy, no warning. The note was never pushed to the server (willPush: false, and the server ends with one contentless frame) and never reached IndexedDB (idbBytes: 0), so the content existed only in one process's memory — and then that was overwritten too. The recovered vault finding an empty file is the downstream symptom.

One real defect found and fixed (c3b8afd, branch fix-recovery-empty-overwrite): content-sync.ts registered two listeners on the same synced:<doc> event. The first set hasSyncedOnce and scheduled a disk write; the second seeded the document from the file. Seeding is asynchronous and hasSyncedOnce is exactly what disarms the guard against blanking a file from an empty document, so the outcome depended on which continuation won. Now one handler: seed, then confirm, then write.

It is not sufficient. With that fix the scenario still failed 2 runs in 10, with the same signature. The open question is narrow and specific: what empties the document between the successful seed and the disk write? It happens around the password reset, which invalidates the writer's session. A rebuild of the document after reconnect, from an IndexedDB that holds nothing, would produce exactly this.

Suggested next steps, in order:

  1. Log every ytext transaction's origin and resulting length for one document, and run until failure. That names the emptier in one run instead of by argument.
  2. Whatever the cause, the guard in writeToDisk is keyed on hasSyncedOnce, which means "the provider reported synced", not "the server has delivered this document's content". Those differ, and the difference is what destroys the file. Consider refusing to write an empty document over a non-empty file at all without positive evidence the emptiness is a real deletion, and taking a .nectenda-backups/ copy when it does. CLAUDE.md: a spurious backup costs a file, a missed one costs someone's work.
  3. The upload assertion in test 1 counts rows in doc_updates rather than bytes, so it passes on a contentless frame. It was added to catch exactly this and does not. Make it assert the content is recoverable from what the server holds.

Full multi-vault suite is green with the partial fix: 57 passed, 2 skipped. The branch is pushed and not merged.

Not closed. Here is what the evidence actually says, so the next run does not repeat the dead ends. **The bisect is void — the test is flaky, not newly broken.** `git bisect` blamed 35360f5 ("Use Obsidian's own grouped-list markup"), a settings-pane commit. Checking that verdict rather than accepting it: at 35360f5 the scenario passes twice and fails once, and at its parent it passes three times out of three. A one-run-per-step bisect against a test that fails roughly one run in three will blame an arbitrary commit. So the window 13→14 September is where the failure rate crossed the threshold of being noticed, not where a regression landed. Treat `recovery.test.ts` as long-standing and intermittent. **It is worse than a reader failing to receive.** The writer's own vault destroys the note. From `diag-A.log` on a failing run: ``` 11:01:33.403 Computed the delta the server is missing {docName: 4b1dbbef…, deltaBytes: 2, willPush: false} 11:01:33.904 Synced content already on disk {path: before-the-reset.md, bytes: 42, hasSyncedOnce: true} 11:01:34.986 Writing synced content to disk {path: before-the-reset.md, diskBytes: 42, docBytes: 0} ``` The document holds the 42 bytes at 33.904 and is empty at 34.986, and the empty document is then written over the file. No conflict copy, no warning. The note was never pushed to the server (`willPush: false`, and the server ends with one contentless frame) and never reached IndexedDB (`idbBytes: 0`), so the content existed only in one process's memory — and then that was overwritten too. The recovered vault finding an empty file is the downstream symptom. **One real defect found and fixed** (c3b8afd, branch `fix-recovery-empty-overwrite`): `content-sync.ts` registered two listeners on the same `synced:<doc>` event. The first set `hasSyncedOnce` and scheduled a disk write; the second seeded the document from the file. Seeding is asynchronous and `hasSyncedOnce` is exactly what disarms the guard against blanking a file from an empty document, so the outcome depended on which continuation won. Now one handler: seed, then confirm, then write. **It is not sufficient.** With that fix the scenario still failed 2 runs in 10, with the same signature. The open question is narrow and specific: **what empties the document between the successful seed and the disk write?** It happens around the password reset, which invalidates the writer's session. A rebuild of the document after reconnect, from an IndexedDB that holds nothing, would produce exactly this. **Suggested next steps**, in order: 1. Log every `ytext` transaction's origin and resulting length for one document, and run until failure. That names the emptier in one run instead of by argument. 2. Whatever the cause, the guard in `writeToDisk` is keyed on `hasSyncedOnce`, which means "the provider reported synced", not "the server has delivered this document's content". Those differ, and the difference is what destroys the file. Consider refusing to write an empty document over a non-empty file at all without positive evidence the emptiness is a real deletion, and taking a `.nectenda-backups/` copy when it does. `CLAUDE.md`: a spurious backup costs a file, a missed one costs someone's work. 3. The upload assertion in test 1 counts rows in `doc_updates` rather than bytes, so it passes on a contentless frame. It was added to catch exactly this and does not. Make it assert the content is recoverable from what the server holds. Full multi-vault suite is green with the partial fix: 57 passed, 2 skipped. The branch is pushed and not merged.
Author
Owner

Fixed and merged to main as 8bd2113 (with c3b8afd).

What it was. Instrumenting every transaction on the document named it in one run. The recovered vault destroys the note:

B  Create accepted              (B creates an empty placeholder file)
B  TXN origin=remote  len=42    (the server delivers the content correctly)
B  TXN origin=null    len=0     (B deletes all 42 characters, one ms later)
A  TXN origin=remote  len=0     (A receives B's deletion)
A  Writing synced content to disk {diskBytes: 42, docBytes: 0}

FileSync creates the placeholder as soon as the folder listing names the file. The content then arrives and fills the document. Obsidian's modify event for that placeholder lands after it, and onLocalModify read the empty placeholder as an edit, deleted what had just arrived, and pushed the deletion — so the vault that wrote the note applied it and blanked its own copy too. The writing was gone from both machines with no conflict copy and no warning.

Note what this means for the earlier theory: the content was uploaded and the recovered vault did receive it. Nothing was ever wrong with recovery, the keys, or the identity. The scenario simply happens to put a brand-new vault next to a note it has never held, which is the shape that triggers this. Any first sync of any note could hit it.

Why the existing guard could not help. It permits the write once the server has confirmed the document, and the emptiness the server confirmed was this vault's own. "The server says empty" is not evidence by itself: the server's copy is empty whenever a vault has failed to upload, or another vault has just deleted the content by this same route.

Three changes. An empty file no longer empties a document until this vault has seen the two agree at least once (lastSyncedContent === null already meant exactly that); emptying a file that has held the content is a real edit and still travels. Blanking a file is no longer silent — the local copy goes to .nectenda-backups/ first and the removal is logged. And seeding a document from disk now completes before the document is marked confirmed, so the write scheduled on confirmation cannot beat the content into place; that race was real on its own and is why the first fix was necessary but not sufficient.

Verification. The scenario failed about one run in three before and passed twelve of twelve after. Both new rules are mutation-checked in both directions in empty-document-guard.test.ts. Full multi-vault suite 57 passed; the tree is 899 tests green. docs/sync-limitations.md records the case under a new heading.

Still worth doing, separately. The upload assertion in test 1 counts rows in doc_updates rather than checking content, so it would pass on a contentless frame. It did not mislead here, but its comment claims a guarantee it does not give.

This unblocks #13: the gate on branch cd-phase-3 can now be merged and switched on.

Fixed and merged to main as 8bd2113 (with c3b8afd). **What it was.** Instrumenting every transaction on the document named it in one run. The recovered vault destroys the note: ``` B Create accepted (B creates an empty placeholder file) B TXN origin=remote len=42 (the server delivers the content correctly) B TXN origin=null len=0 (B deletes all 42 characters, one ms later) A TXN origin=remote len=0 (A receives B's deletion) A Writing synced content to disk {diskBytes: 42, docBytes: 0} ``` FileSync creates the placeholder as soon as the folder listing names the file. The content then arrives and fills the document. Obsidian's modify event for that placeholder lands *after* it, and `onLocalModify` read the empty placeholder as an edit, deleted what had just arrived, and pushed the deletion — so the vault that wrote the note applied it and blanked its own copy too. The writing was gone from both machines with no conflict copy and no warning. Note what this means for the earlier theory: the content *was* uploaded and the recovered vault *did* receive it. Nothing was ever wrong with recovery, the keys, or the identity. The scenario simply happens to put a brand-new vault next to a note it has never held, which is the shape that triggers this. Any first sync of any note could hit it. **Why the existing guard could not help.** It permits the write once the server has confirmed the document, and the emptiness the server confirmed was this vault's own. "The server says empty" is not evidence by itself: the server's copy is empty whenever a vault has failed to upload, or another vault has just deleted the content by this same route. **Three changes.** An empty file no longer empties a document until this vault has seen the two agree at least once (`lastSyncedContent === null` already meant exactly that); emptying a file that *has* held the content is a real edit and still travels. Blanking a file is no longer silent — the local copy goes to `.nectenda-backups/` first and the removal is logged. And seeding a document from disk now completes before the document is marked confirmed, so the write scheduled on confirmation cannot beat the content into place; that race was real on its own and is why the first fix was necessary but not sufficient. **Verification.** The scenario failed about one run in three before and passed twelve of twelve after. Both new rules are mutation-checked in both directions in `empty-document-guard.test.ts`. Full multi-vault suite 57 passed; the tree is 899 tests green. `docs/sync-limitations.md` records the case under a new heading. **Still worth doing, separately.** The upload assertion in test 1 counts rows in `doc_updates` rather than checking content, so it would pass on a contentless frame. It did not mislead here, but its comment claims a guarantee it does not give. This unblocks #13: the gate on branch `cd-phase-3` can now be merged and switched on.
Sign in to join this conversation.
No labels
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
Nectenda/nectenda#15
No description provided.