Mail delta catch-up reports a storage error in the workspace test build

kayg commented

2026-10-07 07:38:57 +00:00

Owner

Merge round #1122 found a non-SLOW Mail failure at 5b2825e6cd.

sync::tests::delta_catch_up_shares_the_bounded_window_budget_and_resumes fails in the workspace test build. The fixture has 8,100 UIDs. The first job must commit eight bounded windows, then resume the final window without losing messages or moving the cursor past an uncommitted window.

The continuation reports:

first delta pass failed: Transport; classified log:  WARN mail sync step failed step="cache" error_kind="storage"
test result: FAILED. 127 passed; 1 failed; 6 ignored; 0 measured; 0 filtered out; finished in 43.24s

One unchanged focused run of the workspace binary reproduces it:

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 133 filtered out; finished in 9.58s

Mail, its cache code, Cargo.lock and its library dependency sources are unchanged from origin/dev. A separate baseline runtime build was not made.

A test-only diagnostic experiment logs only the error discriminant and numeric SQLite code; it does not print provider data or the underlying error message. A standalone Mail build passes in 28.58s. A library-only workspace build passes in 28.57s. The latter differs from the failing binary's direct dependency fingerprints only for lightningcss. This does not establish the root cause. An original-target-selection probe is in progress. No existing assertion or fixture changed.

Evidence is in the merge32 worktree under artifacts/merge32: rust-test-continuation.log, mail-delta-focused.log, mail-diagnostic.log and mail-diagnostic-workspace.log. Capture the fixed error class and numeric code in the failing build context before changing cache behavior. Check cursor and transaction rollback invariants in DESIGN §45. Do not classify this as a timing failure without further evidence.

Merge round #1122 found a non-SLOW Mail failure at 5b2825e6cdd16db6a0e32f0fc5aa385634c0b139. `sync::tests::delta_catch_up_shares_the_bounded_window_budget_and_resumes` fails in the workspace test build. The fixture has 8,100 UIDs. The first job must commit eight bounded windows, then resume the final window without losing messages or moving the cursor past an uncommitted window. The continuation reports: ```text first delta pass failed: Transport; classified log: WARN mail sync step failed step="cache" error_kind="storage" test result: FAILED. 127 passed; 1 failed; 6 ignored; 0 measured; 0 filtered out; finished in 43.24s ``` One unchanged focused run of the workspace binary reproduces it: ```text test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 133 filtered out; finished in 9.58s ``` Mail, its cache code, Cargo.lock and its library dependency sources are unchanged from origin/dev. A separate baseline runtime build was not made. A test-only diagnostic experiment logs only the error discriminant and numeric SQLite code; it does not print provider data or the underlying error message. A standalone Mail build passes in 28.58s. A library-only workspace build passes in 28.57s. The latter differs from the failing binary's direct dependency fingerprints only for lightningcss. This does not establish the root cause. An original-target-selection probe is in progress. No existing assertion or fixture changed. Evidence is in the merge32 worktree under artifacts/merge32: rust-test-continuation.log, mail-delta-focused.log, mail-diagnostic.log and mail-diagnostic-workspace.log. Capture the fixed error class and numeric code in the failing build context before changing cache behavior. Check cursor and transaction rollback invariants in DESIGN §45. Do not classify this as a timing failure without further evidence.

kayg commented

2026-10-07 07:45:23 +00:00

Author

Owner

The original target-selection diagnostic reproduced the failure in 6.81s and printed only fixed metadata:

merge32 cache error discriminant=Discriminant(2) numeric_code=5
first delta pass failed: Transport; classified log:  WARN mail sync step failed step="cache" error_kind="storage"
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 133 filtered out; finished in 6.81s

Code 5 is SQLite BUSY. This is a persistent lock-contention finding in the reduced workspace continuation context. The library-only and standalone probes pass, so their result does not resolve it. The context difference and the exact failing command remain in artifacts/merge32/mail-diagnostic-all-targets.log. No underlying error message or provider data was printed.

The temporary diagnostic is removed; git status is clean at 5b2825e6c. No assertion, fixture, timeout or retry limit changed. Mail source and its library dependency sources remain identical to origin/dev. Root cause and baseline runtime comparison remain open. This is not reported as a passing gate or dismissed as SLOW.

The original target-selection diagnostic reproduced the failure in 6.81s and printed only fixed metadata: ```text merge32 cache error discriminant=Discriminant(2) numeric_code=5 first delta pass failed: Transport; classified log: WARN mail sync step failed step="cache" error_kind="storage" test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 133 filtered out; finished in 6.81s ``` Code 5 is SQLite BUSY. This is a persistent lock-contention finding in the reduced workspace continuation context. The library-only and standalone probes pass, so their result does not resolve it. The context difference and the exact failing command remain in artifacts/merge32/mail-diagnostic-all-targets.log. No underlying error message or provider data was printed. The temporary diagnostic is removed; git status is clean at 5b2825e6c. No assertion, fixture, timeout or retry limit changed. Mail source and its library dependency sources remain identical to origin/dev. Root cause and baseline runtime comparison remain open. This is not reported as a passing gate or dismissed as SLOW.

kayg referenced this issue

2026-10-07 07:47:40 +00:00

PROCESS: browser smoke suite of real User flows over a throttled network (deploy gate) #1122

kayg referenced this issue

2026-10-07 07:54:08 +00:00

PROCESS: browser smoke suite of real User flows over a throttled network (deploy gate) #1122

kayg referenced this issue

2026-10-07 07:59:46 +00:00

PROCESS: browser smoke suite of real User flows over a throttled network (deploy gate) #1122

kayg referenced this issue

2026-10-07 08:10:22 +00:00

PROCESS: browser smoke suite of real User flows over a throttled network (deploy gate) #1122

kayg commented

2026-10-07 08:25:38 +00:00

Author

Owner

#1339 reproduced in the workspace-context Mail test binary (calternal_plugin_mail-81e455bc4adbb477):

mail diagnostic store line=1764 code=Some("5")
mail diagnostic store line=1764 code=Some("5")
mail diagnostic store line=1764 code=Some("5")
mail diagnostic store line=1764 code=Some("5")
mail diagnostic store line=1764 code=Some("5")
mail diagnostic authority idle=1 size=1 checkpoint=CheckpointStatus { runs: 16, errors: 0, log_frames: 19005, checkpointed_frames: 19005, elapsed: 141.879285ms, busy: true }
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 134 filtered out; finished in 17.76s

Line 1764 is the mail_thread_keys INSERT, the first main-Index write for that message. commit_window starts BEGIN DEFERRED and reads folder ownership, generation and message/thread state first. Maintenance can take the WAL writer lock between those reads and the first main write. Its TRUNCATE follows a complete PASSIVE pass above the 16 MiB threshold (19,005 frames here). The test has no workers or concurrent authority jobs; its authority connection is idle and its account commit already finished. The separate maintenance connection is the only other active writer in this isolated fixture. A pinned deferred reader cannot safely upgrade while that writer owns the lock, so SQLite returns BUSY at the upgrade instead of waiting with busy_timeout. This is a real product contention bug, not SLOW.

A new one-attempt regression holds BEGIN IMMEDIATE on the authority connection and changes the generation. Before the fix it fails at the same upgrade:

mail diagnostic store line=1808 code=Some("5")
one window attempt must wait before reading, rather than fail a deferred lock upgrade
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 134 filtered out; finished in 0.85s

The product fix uses BEGIN IMMEDIATE in commit_window before any owner/generation read. The existing busy timeout now applies at writer admission. The admitted window must re-read the committed generation and refuse a stale one without publishing messages. No timeout or retry budget changed. There is no provider I/O under this lock. SQL statements and per-window bounds stay unchanged. See SQLite's transaction contract: https://www.sqlite.org/lang_transaction.html#deferred_immediate_and_exclusive_transactions

The temporary numeric/static-location diagnostics are removed. A fresh workspace-context build, the new regression, and 20 consecutive runs of the original delta test follow. Evidence logs remain under artifacts/merge32b/mail-lock-red.log and mail-delta-diagnostic.log.

#1339 reproduced in the workspace-context Mail test binary (calternal_plugin_mail-81e455bc4adbb477): ```text mail diagnostic store line=1764 code=Some("5") mail diagnostic store line=1764 code=Some("5") mail diagnostic store line=1764 code=Some("5") mail diagnostic store line=1764 code=Some("5") mail diagnostic store line=1764 code=Some("5") mail diagnostic authority idle=1 size=1 checkpoint=CheckpointStatus { runs: 16, errors: 0, log_frames: 19005, checkpointed_frames: 19005, elapsed: 141.879285ms, busy: true } test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 134 filtered out; finished in 17.76s ``` Line 1764 is the mail_thread_keys INSERT, the first main-Index write for that message. commit_window starts BEGIN DEFERRED and reads folder ownership, generation and message/thread state first. Maintenance can take the WAL writer lock between those reads and the first main write. Its TRUNCATE follows a complete PASSIVE pass above the 16 MiB threshold (19,005 frames here). The test has no workers or concurrent authority jobs; its authority connection is idle and its account commit already finished. The separate maintenance connection is the only other active writer in this isolated fixture. A pinned deferred reader cannot safely upgrade while that writer owns the lock, so SQLite returns BUSY at the upgrade instead of waiting with busy_timeout. This is a real product contention bug, not SLOW. A new one-attempt regression holds BEGIN IMMEDIATE on the authority connection and changes the generation. Before the fix it fails at the same upgrade: ```text mail diagnostic store line=1808 code=Some("5") one window attempt must wait before reading, rather than fail a deferred lock upgrade test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 134 filtered out; finished in 0.85s ``` The product fix uses BEGIN IMMEDIATE in commit_window before any owner/generation read. The existing busy timeout now applies at writer admission. The admitted window must re-read the committed generation and refuse a stale one without publishing messages. No timeout or retry budget changed. There is no provider I/O under this lock. SQL statements and per-window bounds stay unchanged. See SQLite's transaction contract: https://www.sqlite.org/lang_transaction.html#deferred_immediate_and_exclusive_transactions The temporary numeric/static-location diagnostics are removed. A fresh workspace-context build, the new regression, and 20 consecutive runs of the original delta test follow. Evidence logs remain under artifacts/merge32b/mail-lock-red.log and mail-delta-diagnostic.log.

kayg referenced this issue

2026-10-07 08:25:39 +00:00

PROCESS: browser smoke suite of real User flows over a throttled network (deploy gate) #1122

kayg commented

2026-10-07 08:40:03 +00:00

Author

Owner

#1339 reproduced in the workspace-context Mail test binary (calternal_plugin_mail-81e455bc4adbb477):

mail diagnostic store line=1764 code=Some("5")
mail diagnostic store line=1764 code=Some("5")
mail diagnostic store line=1764 code=Some("5")
mail diagnostic store line=1764 code=Some("5")
mail diagnostic store line=1764 code=Some("5")
mail diagnostic authority idle=1 size=1 checkpoint=CheckpointStatus { runs: 16, errors: 0, log_frames: 19005, checkpointed_frames: 19005, elapsed: 141.879285ms, busy: true }
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 134 filtered out; finished in 17.76s

Line 1764 is the mail_thread_keys INSERT, the first main-Index write for that message. commit_window starts BEGIN DEFERRED and reads folder ownership, generation and message/thread state first. Maintenance can take the WAL writer lock between those reads and the first main write. Its TRUNCATE follows a complete PASSIVE pass above the 16 MiB threshold (19,005 frames here). The test has no workers or concurrent authority jobs; its authority connection is idle and its account commit already finished. The separate maintenance connection is the only other active writer in this isolated fixture. A pinned deferred reader cannot safely upgrade while that writer owns the lock, so SQLite returns BUSY at the upgrade instead of waiting with busy_timeout. This is a real product contention bug, not SLOW.

A new one-attempt regression holds BEGIN IMMEDIATE on the authority connection and changes the generation. Before the fix it fails at the same upgrade:

mail diagnostic store line=1808 code=Some("5")
one window attempt must wait before reading, rather than fail a deferred lock upgrade
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 134 filtered out; finished in 0.85s

The product fix uses BEGIN IMMEDIATE in commit_window before any owner/generation read. The existing busy timeout now applies at writer admission. The admitted window must re-read the committed generation and refuse a stale one without publishing messages. No timeout or retry budget changed. There is no provider I/O under this lock. SQL statements and per-window bounds stay unchanged. See SQLite's transaction contract: https://www.sqlite.org/lang_transaction.html#deferred_immediate_and_exclusive_transactions

The temporary numeric/static-location diagnostics are removed. A fresh workspace-context build, the new regression, and 20 consecutive runs of the original delta test follow. Evidence logs remain under artifacts/merge32b/mail-lock-red.log and mail-delta-diagnostic.log.

Validation complete: the fresh workspace-built binary passes the new one-attempt regression, then the original delta catch-up test passes 20 consecutive runs (22.18–32.15 seconds each). The complete Mail suite passes 129 tests, with 6 ignored and 0 failures. Per-crate clippy and cargo fmt --check exit 0. The product fix is committed as 0b4a3aca06. No temporary diagnostics remain.

#1339 reproduced in the workspace-context Mail test binary (calternal_plugin_mail-81e455bc4adbb477): ```text mail diagnostic store line=1764 code=Some("5") mail diagnostic store line=1764 code=Some("5") mail diagnostic store line=1764 code=Some("5") mail diagnostic store line=1764 code=Some("5") mail diagnostic store line=1764 code=Some("5") mail diagnostic authority idle=1 size=1 checkpoint=CheckpointStatus { runs: 16, errors: 0, log_frames: 19005, checkpointed_frames: 19005, elapsed: 141.879285ms, busy: true } test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 134 filtered out; finished in 17.76s ``` Line 1764 is the mail_thread_keys INSERT, the first main-Index write for that message. commit_window starts BEGIN DEFERRED and reads folder ownership, generation and message/thread state first. Maintenance can take the WAL writer lock between those reads and the first main write. Its TRUNCATE follows a complete PASSIVE pass above the 16 MiB threshold (19,005 frames here). The test has no workers or concurrent authority jobs; its authority connection is idle and its account commit already finished. The separate maintenance connection is the only other active writer in this isolated fixture. A pinned deferred reader cannot safely upgrade while that writer owns the lock, so SQLite returns BUSY at the upgrade instead of waiting with busy_timeout. This is a real product contention bug, not SLOW. A new one-attempt regression holds BEGIN IMMEDIATE on the authority connection and changes the generation. Before the fix it fails at the same upgrade: ```text mail diagnostic store line=1808 code=Some("5") one window attempt must wait before reading, rather than fail a deferred lock upgrade test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 134 filtered out; finished in 0.85s ``` The product fix uses BEGIN IMMEDIATE in commit_window before any owner/generation read. The existing busy timeout now applies at writer admission. The admitted window must re-read the committed generation and refuse a stale one without publishing messages. No timeout or retry budget changed. There is no provider I/O under this lock. SQL statements and per-window bounds stay unchanged. See SQLite's transaction contract: https://www.sqlite.org/lang_transaction.html#deferred_immediate_and_exclusive_transactions The temporary numeric/static-location diagnostics are removed. A fresh workspace-context build, the new regression, and 20 consecutive runs of the original delta test follow. Evidence logs remain under artifacts/merge32b/mail-lock-red.log and mail-delta-diagnostic.log. Validation complete: the fresh workspace-built binary passes the new one-attempt regression, then the original delta catch-up test passes 20 consecutive runs (22.18–32.15 seconds each). The complete Mail suite passes 129 tests, with 6 ignored and 0 failures. Per-crate clippy and cargo fmt --check exit 0. The product fix is committed as 0b4a3aca06aabf85d388225006686a11de31fb2a. No temporary diagnostics remain.

kayg referenced this issue

2026-10-07 08:41:34 +00:00

PROCESS: browser smoke suite of real User flows over a throttled network (deploy gate) #1122

kayg referenced this issue

2026-10-07 09:59:16 +00:00

PROCESS: browser smoke suite of real User flows over a throttled network (deploy gate) #1122

Rows
Columns

Mail delta catch-up reports a storage error in the workspace test build #1339