Mail provider sync reports invalid responses after native Mail transfers

kayg commented

2026-10-04 06:26:52 +00:00

Owner

Observed in the real Apple Mail acceptance for #486, with the isolated Dovecot TLS fixture and server HEAD 197e382954.

After native archive commands complete (UID COPY → UID STORE → UID EXPUNGE), Mail provider sync reports The IMAP server sent an invalid response. twice, at 2026-10-04T06:18:04Z and 06:18:33Z. Recorded durations are 1868 ms and 1639 ms. These are protocol errors, not SLOW-only load findings. The same run also has provider timeouts of about 302–304 seconds during the large initial client download.

The provider is reachable by an independent TLS IMAP read in about 1–2 seconds. The native archive receipts are correct: one destination per Message-ID and source removal. Delete later reaches the correct own-account Trash and removes the source. The open web Inbox updates without reload. No new Mail crash report has appeared at this checkpoint. A causal relationship between the sync errors and delayed native commands is not established.

Reproduce with tests/adversarial/mail-sync.md, real Apple Mail and the populated Dovecot fixture. Enable the bounded fixture transcript and collect only sanitized events. Investigate the sync parsing/IDLE path and add a focused regression once the exact response is known. Do not publish raw credentials or Mail bodies. The private fixture remains local.

Observed in the real Apple Mail acceptance for #486, with the isolated Dovecot TLS fixture and server HEAD 197e3829546e44dbd83ce813472989fc40cb37d8. After native archive commands complete (UID COPY → UID STORE → UID EXPUNGE), Mail provider sync reports `The IMAP server sent an invalid response.` twice, at 2026-10-04T06:18:04Z and 06:18:33Z. Recorded durations are 1868 ms and 1639 ms. These are protocol errors, not SLOW-only load findings. The same run also has provider timeouts of about 302–304 seconds during the large initial client download. The provider is reachable by an independent TLS IMAP read in about 1–2 seconds. The native archive receipts are correct: one destination per Message-ID and source removal. Delete later reaches the correct own-account Trash and removes the source. The open web Inbox updates without reload. No new Mail crash report has appeared at this checkpoint. A causal relationship between the sync errors and delayed native commands is not established. Reproduce with tests/adversarial/mail-sync.md, real Apple Mail and the populated Dovecot fixture. Enable the bounded fixture transcript and collect only sanitized events. Investigate the sync parsing/IDLE path and add a focused regression once the exact response is known. Do not publish raw credentials or Mail bodies. The private fixture remains local.

kayg referenced this issue

2026-10-04 06:40:26 +00:00

calternaldav: IMAP mail proxy, all Connected Accounts as one mail account (grill) #486

kayg referenced this issue

2026-10-04 06:58:25 +00:00

Mail: Apple Mail move/delete receipts remain incomplete #1032

kayg referenced this issue

2026-10-04 06:58:26 +00:00

Mail: real Apple Mail acceptance crashes during mailbox mutations #1031

kayg referenced this issue

2026-10-04 06:58:27 +00:00

calternaldav: IMAP mail proxy, all Connected Accounts as one mail account (grill) #486

kayg commented

2026-10-04 07:01:51 +00:00

Author

Owner

Started work on job/syncerr-1037 from job/mailproxy-486 at base 86f2e061e6363d837d122574530e44caf843e47d. I will reproduce the UID COPY → UID STORE → UID EXPUNGE sequence and IDLE against the local Dovecot TLS fixture while provider sync runs, capture only the bounded sanitized fixture transcript, and add a regression for the exact rejected response. I will also trace and fix the initial-backfill timeout with bounded batching or a progress-based deadline. No Mac session is needed for this job.

Started work on `job/syncerr-1037` from `job/mailproxy-486` at base `86f2e061e6363d837d122574530e44caf843e47d`. I will reproduce the UID COPY → UID STORE → UID EXPUNGE sequence and IDLE against the local Dovecot TLS fixture while provider sync runs, capture only the bounded sanitized fixture transcript, and add a regression for the exact rejected response. I will also trace and fix the initial-backfill timeout with bounded batching or a progress-based deadline. No Mac session is needed for this job.

kayg referenced this issue

2026-10-04 07:10:58 +00:00

Mail proxy: crash-proof it under overload and bizarre scenarios #1038

kayg referenced this issue

2026-10-04 07:12:46 +00:00

Mail proxy: crash-proof it under overload and bizarre scenarios #1038

kayg commented

2026-10-04 07:37:15 +00:00

Author

Owner

Additional #1038 fixture evidence, using the pre-existing mail-test-provider binary from this worktree: three generated local Dovecot accounts (64, 32 and 32 Inbox messages), plus the first account boundary folder (50 MiB, empty message, duplicate and missing Message-ID). All account-creation calls returned 201 and App Password calls returned 200. After normal Connected Account reconciliation on restart, not all accounts reported last_sync_at and backfill_complete within 180 seconds. The status API reported zero accounts with last_error during that window. A read-only count at about two minutes showed 109 folders and only one account with last_sync_ms. This does not reproduce the invalid-response text or establish the cause; it is a bounded initial-sync completion failure for your investigation. No sync code was changed here. A focused ordinary-message smoke omits the boundary folder; full boundary acceptance remains with the merge round.

kayg commented

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

Author

Owner

Timing caveat for the preceding #1038 evidence: the small stress fixture reused the default initial UID ceiling 12658. A 32-message initial Inbox therefore required about 159 80-UID backfill windows, before new sentinels. An ordinary-message retry without the Boundary folder also completed only two accounts in 180 seconds with zero reported errors. Stress fixtures now use dense initial UIDs; #613 keeps its original gaps and UIDNEXT, with a regression for both layouts. These timings are SLOW-only fixture evidence, not evidence that the 50 MiB message caused a provider defect. A final focused smoke uses the corrected UID range.

kayg commented

2026-10-04 07:46:30 +00:00

Author

Owner

Final #1038 focused retry still failed initial sync after 180 seconds. This fixture used dense initial UIDs, 64/32/32 ordinary Inbox messages, 16 empty Bulk folders, and no Boundary folder or deep hierarchy. After the normal reconciliation restart, the status API repeatedly returned 200 with completed_accounts=2, inbox_counts=[64,0,32], accounts_with_errors=0. The coordinator stopped at the prerequisite and cleaned up its server, browser and Dovecot container. One preceding dense smoke completed all three accounts and passed both short command phases, so this is intermittent sync/restart evidence. No invalid-response text, crash or panic was established. The final strengthened MIME/Flagged receipt phase was not reached. No provider-sync code was changed here; this evidence is for #1037.

kayg referenced this issue

2026-10-04 07:48:25 +00:00

Mail proxy: crash-proof it under overload and bizarre scenarios #1038

kayg commented

2026-10-04 07:59:35 +00:00

Author

Owner

#1038 continuation: deterministic restart recovery defect found in calternal-db's Worker::run, not the provider parser. Worker::run calls recover_expired_leases only once at startup. The server lease is 120 s. A process that restarts before an interrupted Mail sync lease expires leaves that job leased forever: after startup there is no lease recovery upkeep. Two other accounts can sync and enter IDLE while the third never starts, so no provider error is recorded.

A fresh deterministic regression queues three mail.sync jobs, leases one to an interrupted worker for 120 s, starts a replacement worker, observes the two fresh jobs complete, then expires the interrupted lease. The third job never completes. Verbatim result:

Mail sync lease expired after startup but was never recovered
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.12s
error: test failed, to rerun pass `-p calternal-db --test mailstress_restart`

The fresh local-provider live run also starts with completed_accounts=2, inbox_counts=[64,32,0], accounts_with_errors=0. Queue evidence at the deadline will follow. This is separate from #1037's invalid-response/download-timeout defect. No provider sync functions were changed. The local job/syncerr-1037 ref still has no commits beyond job/mailproxy-486. Proposed fix: periodic shared worker lease recovery. The job's cross-crate behavioral-change rule requires scope confirmation; that question is pending. No production fix has been applied yet.

#1038 continuation: deterministic restart recovery defect found in calternal-db's Worker::run, not the provider parser. Worker::run calls recover_expired_leases only once at startup. The server lease is 120 s. A process that restarts before an interrupted Mail sync lease expires leaves that job leased forever: after startup there is no lease recovery upkeep. Two other accounts can sync and enter IDLE while the third never starts, so no provider error is recorded. A fresh deterministic regression queues three mail.sync jobs, leases one to an interrupted worker for 120 s, starts a replacement worker, observes the two fresh jobs complete, then expires the interrupted lease. The third job never completes. Verbatim result: ```text Mail sync lease expired after startup but was never recovered test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.12s error: test failed, to rerun pass `-p calternal-db --test mailstress_restart` ``` The fresh local-provider live run also starts with completed_accounts=2, inbox_counts=[64,32,0], accounts_with_errors=0. Queue evidence at the deadline will follow. This is separate from #1037's invalid-response/download-timeout defect. No provider sync functions were changed. The local job/syncerr-1037 ref still has no commits beyond job/mailproxy-486. Proposed fix: periodic shared worker lease recovery. The job's cross-crate behavioral-change rule requires scope confirmation; that question is pending. No production fix has been applied yet.

kayg referenced this issue

2026-10-04 07:59:35 +00:00

Mail proxy: crash-proof it under overload and bizarre scenarios #1038

kayg commented

2026-10-04 08:02:00 +00:00

Author

Owner

Fresh server built from this branch; isolated generated Dovecot fixture. Initial sync stalled through 180 s with completed_accounts=2, inbox_counts=[64,32,0], accounts_with_errors=0. At the deadline all three mail.sync jobs were still leased and ALL THREE leases were expired:

{"scenario":"initial-sync","result":"FAIL","accounts_with_errors":0,"sync_error_owner":null}
{"scenario": "sync-queue-at-deadline", "states": [{"state": "leased", "count": 3, "expired_leases": 3}]}

This matches the deterministic regression and confirms the production failure mechanism: restart occurs while leases remain live; startup recovery finds none expired; all interrupted jobs stay leased after their deadlines. Accounts that had already committed their backfill look complete; the uncommitted account remains empty with no error because no new provider attempt runs. No provider parser or scheduling functions were changed. A single diagnostic restart after expiry is being used to isolate the COPY/MOVE receipt check. It will not count as automatic recovery.

Fresh server built from this branch; isolated generated Dovecot fixture. Initial sync stalled through 180 s with completed_accounts=2, inbox_counts=[64,32,0], accounts_with_errors=0. At the deadline all three mail.sync jobs were still leased and ALL THREE leases were expired: ```json {"scenario":"initial-sync","result":"FAIL","accounts_with_errors":0,"sync_error_owner":null} {"scenario": "sync-queue-at-deadline", "states": [{"state": "leased", "count": 3, "expired_leases": 3}]} ``` This matches the deterministic regression and confirms the production failure mechanism: restart occurs while leases remain live; startup recovery finds none expired; all interrupted jobs stay leased after their deadlines. Accounts that had already committed their backfill look complete; the uncommitted account remains empty with no error because no new provider attempt runs. No provider parser or scheduling functions were changed. A single diagnostic restart after expiry is being used to isolate the COPY/MOVE receipt check. It will not count as automatic recovery.

kayg referenced this issue

2026-10-04 08:08:11 +00:00

Mail proxy: crash-proof it under overload and bizarre scenarios #1038

kayg commented

2026-10-04 08:08:11 +00:00

Author

Owner

Final #1038 evidence at cae707d272: the second focused run reproduced three expired mail.sync leases at the 180 s deadline, with two completed accounts and Inbox counts [64,32,0], no errors. ONE diagnostic restart after expiry completed initial sync. Both subsequent transfer phases passed exact MIME, flags and folder-count checks upstream and locally, and all three web sessions/readiness stayed available. The overall run correctly exited 1 because automatic initial-sync recovery failed. No provider sync functions changed; no overlap with #1037 parser work. Shared Jobs recovery remains unfixed pending the job's cross-crate scope confirmation. Full report is on #1038; READY FOR MERGE: no.

Final #1038 evidence at cae707d27234b7111a35c8f70dfa928acc308433: the second focused run reproduced three expired mail.sync leases at the 180 s deadline, with two completed accounts and Inbox counts [64,32,0], no errors. ONE diagnostic restart after expiry completed initial sync. Both subsequent transfer phases passed exact MIME, flags and folder-count checks upstream and locally, and all three web sessions/readiness stayed available. The overall run correctly exited 1 because automatic initial-sync recovery failed. No provider sync functions changed; no overlap with #1037 parser work. Shared Jobs recovery remains unfixed pending the job's cross-crate scope confirmation. Full report is on #1038; READY FOR MERGE: no.

kayg commented

2026-10-04 08:08:40 +00:00

Author

Owner

Finding: the provider IDLE wait uses wait_with_timeout(300s), whose timeout resets on every response, inside an absolute 301s timeout that maps to ImapError::Timeout. A fixture replay that sends keepalives every 5 ms keeps the inactivity timer alive while the absolute deadline expires; the regression test now checks that this ends IDLE with DONE and does not fail sync.

Finding: the vendored FETCH parser returns every untagged FETCH to a UID FETCH stream. A concurrent flag update shaped as FETCH (FLAGS (...)) has no UID, so the sync path previously returned ImapError::Protocol. The focused replay now skips only a flag-only response, verifies the fetched UIDs against UID SEARCH ALL before returning the page, retries one mismatch, and rejects a second mismatch without committing the cursor.

Finding: the provider IDLE wait uses `wait_with_timeout(300s)`, whose timeout resets on every response, inside an absolute `301s` timeout that maps to `ImapError::Timeout`. A fixture replay that sends keepalives every 5 ms keeps the inactivity timer alive while the absolute deadline expires; the regression test now checks that this ends IDLE with `DONE` and does not fail sync. Finding: the vendored FETCH parser returns every untagged `FETCH` to a `UID FETCH` stream. A concurrent flag update shaped as `FETCH (FLAGS (...))` has no UID, so the sync path previously returned `ImapError::Protocol`. The focused replay now skips only a flag-only response, verifies the fetched UIDs against `UID SEARCH ALL` before returning the page, retries one mismatch, and rejects a second mismatch without committing the cursor.

kayg referenced this issue from a commit

2026-10-04 08:23:43 +00:00

fix(mail): bound IDLE and verify interleaved FETCH pages (#1037)

kayg referenced this issue from a commit

2026-10-04 09:04:48 +00:00

test(mail): queue the sync replay and report its progress (#1037)

kayg referenced this issue from a commit

2026-10-04 09:04:48 +00:00

fix(mail): keep transcript-only names lint-clean (#1037)

kayg referenced this issue

2026-10-04 09:25:03 +00:00

Mail proxy: crash-proof it under overload and bizarre scenarios #1038

kayg commented

2026-10-04 09:31:23 +00:00

Author

Owner

#1037 completion report

Branch: job/syncerr-1037
Head: b7ce415cbaa39f76ba76397baa934b4f96e27600
Merged origin/dev at d513c574b before final gates. No push, deploy, or merge to a shared branch was done.

Changes

Provider IDLE now ends its bounded five-minute window with DONE as normal completion even when keepalives keep resetting the library inactivity timer. This prevents a healthy IDLE session from becoming a provider timeout.
The sync FETCH path recognizes a pushed FLAGS-only FETCH, including one that has a UID but no message attributes. It validates the complete page against UID SEARCH ALL, retries one mismatch, and rejects a second mismatch before any page cursor is committed.
Added a strict fake IMAP replay with * 1 FETCH (FLAGS (\\Seen)) and * 2 FETCH (UID 2 FLAGS (\\Seen)) interleaved before the requested page, plus an IDLE keepalive replay that proves DONE is sent without a timeout.
Added an opt-in, 256-event sanitized transcript. It records static response categories and attribute presence only; it never records mailbox names, UIDs, flags, response text, credentials, or message data.
Extended the Dovecot TLS fixture to run provider sync through IDLE while a scripted proxy client issues UID COPY, UID STORE, and UID EXPUNGE, then verifies the upstream Archive receipt and source removal.
Added a local profile for the recovery path.

Evidence and remaining gap

A prior live Dovecot replay passed the receipt checks for UID COPY, UID STORE, and UID EXPUNGE, and the provider IDLE transcript showed a mailbox FLAGS response. The real fixture did not reproduce a flag-only FETCH inside a sync UID FETCH or the original tagged-response mismatch; the focused unit replay covers the flag-only FETCH shape directly.

The latest explicit-queue E2E attempt waited 360 seconds without a page commit. Its bounded state was:

MAIL_SYNC_STATE {"enabled":true,"backfill_complete":false,"has_last_attempt":true,"has_last_sync":false,"folder_message_counts":[]}
MAIL_SYNC_PAGE_COMMITS 0
AssertionError: Populated provider sync completed

There was no last_error and no provider transcript event in that attempt. Earlier live receipt checks passed, but this latest run does not establish that the complete populated backfill and race test now passes. The issue remains open pending one successful run of:

(cd apps/web && bun run build)
cargo build -p calternal-server --features mail-test-provider
CALTERNAL_MAIL_PROXY_POPULATED=1 CALTERNAL_MAIL_SYNC_RACE=1 node apps/web/e2e/mail-proxy-486.mjs

Local profile

No comparable Mail sync profile exists in docs/perf/baseline.json. The local run had load average 27.42 before and 27.23 after. For the 2,000-UID mailbox, page p50 was 85.67 ms and p95 was 107.43 ms; average worker CPU was 37.96%, mean RSS was 17.0 MB, and peak RSS was 21.9 MB. The 100,000-UID case took 5.21 s for the page and peaked at 28.9 MB RSS. Three-worker burst page times were 51.63, 57.23, and 39.02 ms. These are local measurements under a busy shared host, not a baseline comparison.

Decisions not specified by DESIGN

Use one retry after a live UID-set mismatch, then return a protocol error without committing the page.
Treat the absolute IDLE window as normal completion and send DONE, even when server keepalives continue.
Profile an 80-message page against 2,000 UIDs for average runs and 100,000 UIDs for the worst case, with a three-worker burst.

Gate output

cargo fmt --check completed with exit code 0 and no output.

$ cargo clippy -p calternal-plugin-mail --all-targets -- -D warnings
    Checking calternal-plugin-mail v0.0.1 (/home/kayg/Developer/calternal-wt/syncerr-1037/crates/plugins/mail)
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 11.45s

$ cargo test -p calternal-plugin-mail
test result: ok. 84 passed; 0 failed; 6 ignored; 0 measured; 0 filtered out; finished in 5.24s
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

$ cargo clippy -p calternal-server --all-targets -- -D warnings
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 10m 22s

$ cargo test -p calternal-server
test result: ok. 169 passed; 0 failed; 6 ignored; 0 measured; 0 filtered out; finished in 40.53s

$ bun run check
$ node scripts/check-user-storage.mjs && node scripts/check-type-tokens.mjs && node scripts/check-motion-tokens.mjs && svelte-kit sync && svelte-check --tsconfig ./tsconfig.json
User browser caches use userStorage; only documented device/public-link exceptions remain.
Text sizes and UI shape values use shared role tokens.
UI transitions and animation options use shared motion tokens or documented exceptions.
Loading svelte-check in workspace: /home/kayg/Developer/calternal-wt/syncerr-1037/apps/web
Getting Svelte diagnostics...
svelte-check found 0 errors and 0 warnings

node --check apps/web/e2e/mail-proxy-486.mjs completed with exit code 0 and no output. bun run build completed with exit code 0. cargo clean completed with exit code 0 (Removed 18797 files, 9.5GiB total).

READY FOR MERGE: no. The latest populated-provider E2E run did not complete backfill; please rerun the command above in the merge round. The Rust and web gates passed.

## #1037 completion report Branch: `job/syncerr-1037` Head: `b7ce415cbaa39f76ba76397baa934b4f96e27600` Merged `origin/dev` at `d513c574b` before final gates. No push, deploy, or merge to a shared branch was done. ### Changes - Provider IDLE now ends its bounded five-minute window with `DONE` as normal completion even when keepalives keep resetting the library inactivity timer. This prevents a healthy IDLE session from becoming a provider timeout. - The sync FETCH path recognizes a pushed `FLAGS`-only FETCH, including one that has a UID but no message attributes. It validates the complete page against `UID SEARCH ALL`, retries one mismatch, and rejects a second mismatch before any page cursor is committed. - Added a strict fake IMAP replay with `* 1 FETCH (FLAGS (\\Seen))` and `* 2 FETCH (UID 2 FLAGS (\\Seen))` interleaved before the requested page, plus an IDLE keepalive replay that proves `DONE` is sent without a timeout. - Added an opt-in, 256-event sanitized transcript. It records static response categories and attribute presence only; it never records mailbox names, UIDs, flags, response text, credentials, or message data. - Extended the Dovecot TLS fixture to run provider sync through IDLE while a scripted proxy client issues UID COPY, UID STORE, and UID EXPUNGE, then verifies the upstream Archive receipt and source removal. - Added a local profile for the recovery path. ### Evidence and remaining gap A prior live Dovecot replay passed the receipt checks for UID COPY, UID STORE, and UID EXPUNGE, and the provider IDLE transcript showed a mailbox `FLAGS` response. The real fixture did not reproduce a flag-only FETCH inside a sync UID FETCH or the original tagged-response mismatch; the focused unit replay covers the flag-only FETCH shape directly. The latest explicit-queue E2E attempt waited 360 seconds without a page commit. Its bounded state was: ```text MAIL_SYNC_STATE {"enabled":true,"backfill_complete":false,"has_last_attempt":true,"has_last_sync":false,"folder_message_counts":[]} MAIL_SYNC_PAGE_COMMITS 0 AssertionError: Populated provider sync completed ``` There was no `last_error` and no provider transcript event in that attempt. Earlier live receipt checks passed, but this latest run does not establish that the complete populated backfill and race test now passes. The issue remains open pending one successful run of: ```sh (cd apps/web && bun run build) cargo build -p calternal-server --features mail-test-provider CALTERNAL_MAIL_PROXY_POPULATED=1 CALTERNAL_MAIL_SYNC_RACE=1 node apps/web/e2e/mail-proxy-486.mjs ``` ### Local profile No comparable Mail sync profile exists in `docs/perf/baseline.json`. The local run had load average 27.42 before and 27.23 after. For the 2,000-UID mailbox, page p50 was 85.67 ms and p95 was 107.43 ms; average worker CPU was 37.96%, mean RSS was 17.0 MB, and peak RSS was 21.9 MB. The 100,000-UID case took 5.21 s for the page and peaked at 28.9 MB RSS. Three-worker burst page times were 51.63, 57.23, and 39.02 ms. These are local measurements under a busy shared host, not a baseline comparison. ### Decisions not specified by DESIGN - Use one retry after a live UID-set mismatch, then return a protocol error without committing the page. - Treat the absolute IDLE window as normal completion and send `DONE`, even when server keepalives continue. - Profile an 80-message page against 2,000 UIDs for average runs and 100,000 UIDs for the worst case, with a three-worker burst. ### Gate output `cargo fmt --check` completed with exit code 0 and no output. ```text $ cargo clippy -p calternal-plugin-mail --all-targets -- -D warnings Checking calternal-plugin-mail v0.0.1 (/home/kayg/Developer/calternal-wt/syncerr-1037/crates/plugins/mail) Finished `dev` profile [unoptimized + debuginfo] target(s) in 11.45s $ cargo test -p calternal-plugin-mail test result: ok. 84 passed; 0 failed; 6 ignored; 0 measured; 0 filtered out; finished in 5.24s test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s $ cargo clippy -p calternal-server --all-targets -- -D warnings Finished `dev` profile [unoptimized + debuginfo] target(s) in 10m 22s $ cargo test -p calternal-server test result: ok. 169 passed; 0 failed; 6 ignored; 0 measured; 0 filtered out; finished in 40.53s $ bun run check $ node scripts/check-user-storage.mjs && node scripts/check-type-tokens.mjs && node scripts/check-motion-tokens.mjs && svelte-kit sync && svelte-check --tsconfig ./tsconfig.json User browser caches use userStorage; only documented device/public-link exceptions remain. Text sizes and UI shape values use shared role tokens. UI transitions and animation options use shared motion tokens or documented exceptions. Loading svelte-check in workspace: /home/kayg/Developer/calternal-wt/syncerr-1037/apps/web Getting Svelte diagnostics... svelte-check found 0 errors and 0 warnings ``` `node --check apps/web/e2e/mail-proxy-486.mjs` completed with exit code 0 and no output. `bun run build` completed with exit code 0. `cargo clean` completed with exit code 0 (`Removed 18797 files, 9.5GiB total`). **READY FOR MERGE: no.** The latest populated-provider E2E run did not complete backfill; please rerun the command above in the merge round. The Rust and web gates passed.

kayg commented

2026-10-04 09:36:44 +00:00

Author

Owner

Starting #1037 verification on job/syncerr-1037. The original base was d0fc1f463a31b540fd043a5ced7d0b87aa3602e2; orchestrator merge commit 3a1dd840cf0adf894fc0a9bcbfe7b44f008327de is now HEAD. I will rebuild the branch's mail-test-provider server, replay the populated TLS provider while sampling the durable jobs table, then run the requested repeated replay and IDLE overlap sequence if the first run passes.

Starting #1037 verification on `job/syncerr-1037`. The original base was `d0fc1f463a31b540fd043a5ced7d0b87aa3602e2`; orchestrator merge commit `3a1dd840cf0adf894fc0a9bcbfe7b44f008327de` is now HEAD. I will rebuild the branch's `mail-test-provider` server, replay the populated TLS provider while sampling the durable jobs table, then run the requested repeated replay and IDLE overlap sequence if the first run passes.

kayg commented

2026-10-04 09:42:12 +00:00

Author

Owner

#1038 live long-run evidence, server built from branch job/mailstress-1038 before the two fixture-only commits. Runtime Rust source is the supplied 4f83aef2b baseline (including #1042 recovery).

The local TLS fixture has 100,000 total Inbox messages on User 0, 32 each on Users 1 and 2, 400 Bulk folders plus the 80-level hierarchy. The host budget selected 12 sessions (85 GiB free). The run is still in initial sync; command soak phases have not started.

Two accounts completed. Large Inbox counts progressed through 13,120, 17,360, 18,160 and 19,440. The coordinator's cumulative accounts_with_errors counter changed from 0 to 1. Progress continued after the error. No credentials, provider response strings or message bodies are in this evidence. Error cause and eventual recovery are not established yet. Final results will follow on #1038.

#1038 live long-run evidence, server built from branch `job/mailstress-1038` before the two fixture-only commits. Runtime Rust source is the supplied `4f83aef2b` baseline (including #1042 recovery). The local TLS fixture has 100,000 total Inbox messages on User 0, 32 each on Users 1 and 2, 400 Bulk folders plus the 80-level hierarchy. The host budget selected 12 sessions (85 GiB free). The run is still in initial sync; command soak phases have not started. Two accounts completed. Large Inbox counts progressed through 13,120, 17,360, 18,160 and 19,440. The coordinator's cumulative `accounts_with_errors` counter changed from 0 to 1. Progress continued after the error. No credentials, provider response strings or message bodies are in this evidence. Error cause and eventual recovery are not established yet. Final results will follow on #1038.

kayg commented

2026-10-04 09:51:09 +00:00

Author

Owner

Finding from the first monitored populated-provider replay: the mail.sync row was first leased by the original server at attempt 1. The E2E harness then restarted the server with that lease still active. The replacement server later reclaimed the same Job after lease expiry at attempt 2, with a new leased_by value and a future lease_until. The observer queried only state, leased_by, lease_until and attempts; it did not read the payload. This reproduces the lease-recovery mechanism from #1042 and matches the prior zero-page/no-provider-event stall. The recovered run is still in progress; backfill completion and upstream receipts are not yet established.

Finding from the first monitored populated-provider replay: the `mail.sync` row was first leased by the original server at attempt 1. The E2E harness then restarted the server with that lease still active. The replacement server later reclaimed the same Job after lease expiry at attempt 2, with a new `leased_by` value and a future `lease_until`. The observer queried only `state`, `leased_by`, `lease_until` and `attempts`; it did not read the payload. This reproduces the lease-recovery mechanism from #1042 and matches the prior zero-page/no-provider-event stall. The recovered run is still in progress; backfill completion and upstream receipts are not yet established.

kayg commented

2026-10-04 09:52:23 +00:00

Author

Owner

Replay 1 passed on the merged branch. The bounded jobs-table trace showed the pre-restart mail.sync lease recovered by the replacement worker (attempt 2), then the Job completed. The E2E reported PASS populated Mail projection and Connected Account reconciliation for the 2,000-message fixture. It also reported PASS sync race: provider IDLE and proxy COPY → STORE → EXPUNGE receipt. The replay kept one separate proxy session in IDLE while the second issued COPY, STORE and UID EXPUNGE; the fixture verified exactly one matching Message-ID in upstream Archive and none in upstream INBOX. Repeating the replay twice more now.

Replay 1 passed on the merged branch. The bounded jobs-table trace showed the pre-restart `mail.sync` lease recovered by the replacement worker (attempt 2), then the Job completed. The E2E reported `PASS populated Mail projection and Connected Account reconciliation` for the 2,000-message fixture. It also reported `PASS sync race: provider IDLE and proxy COPY → STORE → EXPUNGE receipt`. The replay kept one separate proxy session in IDLE while the second issued COPY, STORE and UID EXPUNGE; the fixture verified exactly one matching Message-ID in upstream Archive and none in upstream INBOX. Repeating the replay twice more now.

kayg commented

2026-10-04 09:57:23 +00:00

Author

Owner

The full #1038 long-run attempt exited 1 before either soak phase. Fixture: 100,000 total Inbox messages on User 0, 32 each on Users 1 and 2; 400 Bulk folders plus the 80-level hierarchy and boundary messages. Session budget: 12, with 85 GiB free.

At the 900-second initial-sync deadline: Inbox counts [63520,32,32]; two completed accounts; two accounts had reported errors at some point. The current account errors had previously cleared in a read-only diagnostic. Queue: completed 7, dead 1, leased 3, pending 1; expired leases 0. The diagnostic restart also failed its 180-second completion deadline. It remained a failure, and the coordinator cleaned up its private Instance and provider.

A subsequent read-only diagnostic before cleanup found two dead jobs, each with three attempts and a coarse error class other. The Jobs payload and error text were not printed. sync.rs maps failed synchronization to the fixed job message mail provider synchronization failed, so job text does not reveal the provider cause. No claim that this is merely host load, a recovered transfer, or a crash.

The job merged origin/dev once (comment-only conflict, identical authentication code). A bounded continuation retains the same data and command checks: 30 minutes for initial sync, two full 30-minute phases, two-hour total deadline. This corrects the coordinator's arithmetic: its prior 75-minute whole-run budget left no setup/cleanup time after a full 15-minute prerequisite plus both phases. The initial failed attempt remains part of the final results.

The full #1038 long-run attempt exited 1 before either soak phase. Fixture: 100,000 total Inbox messages on User 0, 32 each on Users 1 and 2; 400 Bulk folders plus the 80-level hierarchy and boundary messages. Session budget: 12, with 85 GiB free. At the 900-second initial-sync deadline: Inbox counts `[63520,32,32]`; two completed accounts; two accounts had reported errors at some point. The current account errors had previously cleared in a read-only diagnostic. Queue: completed 7, dead 1, leased 3, pending 1; expired leases 0. The diagnostic restart also failed its 180-second completion deadline. It remained a failure, and the coordinator cleaned up its private Instance and provider. A subsequent read-only diagnostic before cleanup found two dead jobs, each with three attempts and a coarse error class `other`. The Jobs payload and error text were not printed. `sync.rs` maps failed synchronization to the fixed job message `mail provider synchronization failed`, so job text does not reveal the provider cause. No claim that this is merely host load, a recovered transfer, or a crash. The job merged origin/dev once (comment-only conflict, identical authentication code). A bounded continuation retains the same data and command checks: 30 minutes for initial sync, two full 30-minute phases, two-hour total deadline. This corrects the coordinator's arithmetic: its prior 75-minute whole-run budget left no setup/cleanup time after a full 15-minute prerequisite plus both phases. The initial failed attempt remains part of the final results.

kayg commented

2026-10-04 10:02:21 +00:00

Author

Owner

Three-run stability check completed: 3/3 populated-provider replays passed. Each fresh E2E Index showed the mail.sync Job leased by the original server at attempt 1, then reclaimed by the replacement server at attempt 2 after expiry. Each recovered sync completed the 2,000-message backfill and projection. Each IDLE-overlap replay passed UID COPY, UID STORE and UID EXPUNGE; the provider receipt check found exactly one matching Message-ID in Archive and no source copy in INBOX. The sanitized listener transcript showed successful command statuses and COPYUID. No invalid-response error occurred. I am running the final crate gates now.

kayg commented

2026-10-04 10:17:06 +00:00

Author

Owner

#1037 verification completion

Branch: job/syncerr-1037
Head: 833ae1311edd1f070f5df7e3428632c526bd39c
origin/dev was fetched and merged locally before the final gates. No push, deploy or merge to the shared dev branch was done.

What was verified

The previous 360-second no-page/no-transcript stall matches the expired mail.sync lease recovery defect in #1042. The monitored E2E created a mail.sync Job under the first server, restarted the server, and showed the replacement reclaim the expired lease with a new leased_by value and attempt count 2. The Job then completed. This happened in all three fresh fixture runs.

The populated-provider replay passed 3/3 times against the isolated 2,000-message Dovecot TLS fixture. Each run completed backfill and the Mail projection. The second proxy session stayed in IDLE while the first issued UID COPY, UID STORE and UID EXPUNGE. The sanitized transcript showed successful commands; the fixture verified exactly one matching Message-ID in upstream Archive and no source copy in upstream INBOX. No invalid-response error occurred.

The merged auth file has one app_password_revoke_rejects_queued_verification test. It ran successfully; no duplicate test needed removal.

Files

No tracked source files changed in this verification continuation. It used the existing apps/web/e2e/mail-proxy-486.mjs, tests/adversarial/mail_proxy.py and tests/adversarial/mail-sync.md. The production web build and Cargo target output were removed after verification.

Gates

$ cargo fmt --check
(exit 0; no output)

$ cargo clippy -p calternal-auth --all-targets -- -D warnings
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 54.34s

$ cargo test -p calternal-auth
test result: ok. 95 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 37.39s
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

$ cargo clippy -p calternal-plugin-mail --all-targets -- -D warnings
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 35.76s

$ cargo test -p calternal-plugin-mail
test result: ok. 84 passed; 0 failed; 6 ignored; 0 measured; 0 filtered out; finished in 3.71s
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

$ cargo clippy -p calternal-server --all-targets -- -D warnings
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 1m 09s

$ cargo test -p calternal-server
test result: ok. 169 passed; 0 failed; 6 ignored; 0 measured; 0 filtered out; finished in 13.94s

$ bun run build
  Wrote site to "build"
  ✔ done

$ cargo clean
     Removed 17435 files, 9.2GiB total

Decisions and known gaps

No new product or protocol decision was needed. The replay followed the existing fixture procedure. A replacement worker waits for the persisted lease to expire before recovering the Job; the three runs confirmed that it then reclaims and completes the work. This is a bounded restart delay, not the prior permanent lease.

READY FOR MERGE: yes.

## #1037 verification completion Branch: `job/syncerr-1037` Head: `833ae1311edd1f070f5df7e3428632c526bd39c` `origin/dev` was fetched and merged locally before the final gates. No push, deploy or merge to the shared `dev` branch was done. ### What was verified The previous 360-second no-page/no-transcript stall matches the expired `mail.sync` lease recovery defect in #1042. The monitored E2E created a `mail.sync` Job under the first server, restarted the server, and showed the replacement reclaim the expired lease with a new `leased_by` value and attempt count 2. The Job then completed. This happened in all three fresh fixture runs. The populated-provider replay passed 3/3 times against the isolated 2,000-message Dovecot TLS fixture. Each run completed backfill and the Mail projection. The second proxy session stayed in IDLE while the first issued UID COPY, UID STORE and UID EXPUNGE. The sanitized transcript showed successful commands; the fixture verified exactly one matching Message-ID in upstream Archive and no source copy in upstream INBOX. No invalid-response error occurred. The merged auth file has one `app_password_revoke_rejects_queued_verification` test. It ran successfully; no duplicate test needed removal. ### Files No tracked source files changed in this verification continuation. It used the existing `apps/web/e2e/mail-proxy-486.mjs`, `tests/adversarial/mail_proxy.py` and `tests/adversarial/mail-sync.md`. The production web build and Cargo target output were removed after verification. ### Gates ```text $ cargo fmt --check (exit 0; no output) $ cargo clippy -p calternal-auth --all-targets -- -D warnings Finished `dev` profile [unoptimized + debuginfo] target(s) in 54.34s $ cargo test -p calternal-auth test result: ok. 95 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 37.39s test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s $ cargo clippy -p calternal-plugin-mail --all-targets -- -D warnings Finished `dev` profile [unoptimized + debuginfo] target(s) in 35.76s $ cargo test -p calternal-plugin-mail test result: ok. 84 passed; 0 failed; 6 ignored; 0 measured; 0 filtered out; finished in 3.71s test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s $ cargo clippy -p calternal-server --all-targets -- -D warnings Finished `dev` profile [unoptimized + debuginfo] target(s) in 1m 09s $ cargo test -p calternal-server test result: ok. 169 passed; 0 failed; 6 ignored; 0 measured; 0 filtered out; finished in 13.94s $ bun run build Wrote site to "build" ✔ done $ cargo clean Removed 17435 files, 9.2GiB total ``` ### Decisions and known gaps No new product or protocol decision was needed. The replay followed the existing fixture procedure. A replacement worker waits for the persisted lease to expire before recovering the Job; the three runs confirmed that it then reclaims and completes the work. This is a bounded restart delay, not the prior permanent lease. READY FOR MERGE: yes.

kayg commented

2026-10-04 10:52:10 +00:00

Author

Owner

Actual full-duration one-account result from #1038, ordinary fixture, 12 clients:

Elapsed including audit: 1845.99 s. All 12 clients connected. 16,693 SEARCH/FETCH/IDLE/EXPUNGE cycles completed.
20 APPEND, draft-FETCH, STORE, COPY and MOVE commands each returned OK. COPY had 180 clean NO waits; MOVE had 177. No command-loop exception was recorded.
Original audit: 14 exact upstream receipts and 14 exact local receipts completed. One receipt-AssertionError was recorded. The helper records exception types only, so the exact assertion is unavailable. Overall phase result: FAIL. All three retained web sessions and readiness returned 200.
RSS first/last: 153300/263064 KiB; maximum 263064 KiB. Descriptors first/last: 76/96; maximum 143. During the steady command window, descriptors were mostly 135–139 and RSS about 240000–244000 KiB.

A separate read-only audit, while the three-account phase runs, checked all 20 first-phase identities. Local live memberships and flags matched Drafts=0, Archive=1, Trash=1 for every identity. Direct upstream checks found all 40 intentional destination copies, each with exact original MIME and Flagged state. Counts: identities 20, local_counts_ok 20, local_unflagged 0, upstream_counts_ok 20, upstream_bodies_ok 40, upstream_unflagged 0. Elapsed 1.08 s. No message body, Message-ID or credential was printed.

This rules out observed loss/duplication in those checked writes at the later audit time. It does not recheck exact bodies through the proxy or turn the original FAIL into PASS. A 45-second shared audit-budget exhaustion and a cold proxy-body fetch failure are both possible; cause is not established. proxy.rs::body has a 30-second cold upstream read limit. Do not attribute this solely to host load or change expectations to hide it.

The separate existing real Dovecot receipt regression passed: one test, 88 filtered out, 21.41 s. It proves COPY/delete or MOVE ordering and replay without duplicate receipts, not simultaneous mutation acceptance. The three-account 30-minute phase is still running.

Actual full-duration one-account result from #1038, ordinary fixture, 12 clients: - Elapsed including audit: 1845.99 s. All 12 clients connected. 16,693 SEARCH/FETCH/IDLE/EXPUNGE cycles completed. - 20 APPEND, draft-FETCH, STORE, COPY and MOVE commands each returned OK. COPY had 180 clean NO waits; MOVE had 177. No command-loop exception was recorded. - Original audit: 14 exact upstream receipts and 14 exact local receipts completed. One `receipt-AssertionError` was recorded. The helper records exception types only, so the exact assertion is unavailable. Overall phase result: FAIL. All three retained web sessions and readiness returned 200. - RSS first/last: 153300/263064 KiB; maximum 263064 KiB. Descriptors first/last: 76/96; maximum 143. During the steady command window, descriptors were mostly 135–139 and RSS about 240000–244000 KiB. A separate read-only audit, while the three-account phase runs, checked all 20 first-phase identities. Local live memberships and flags matched Drafts=0, Archive=1, Trash=1 for every identity. Direct upstream checks found all 40 intentional destination copies, each with exact original MIME and Flagged state. Counts: identities 20, local_counts_ok 20, local_unflagged 0, upstream_counts_ok 20, upstream_bodies_ok 40, upstream_unflagged 0. Elapsed 1.08 s. No message body, Message-ID or credential was printed. This rules out observed loss/duplication in those checked writes at the later audit time. It does not recheck exact bodies through the proxy or turn the original FAIL into PASS. A 45-second shared audit-budget exhaustion and a cold proxy-body fetch failure are both possible; cause is not established. `proxy.rs::body` has a 30-second cold upstream read limit. Do not attribute this solely to host load or change expectations to hide it. The separate existing real Dovecot receipt regression passed: one test, 88 filtered out, 21.41 s. It proves COPY/delete or MOVE ordering and replay without duplicate receipts, not simultaneous mutation acceptance. The three-account 30-minute phase is still running.

kayg referenced this issue

2026-10-04 11:19:57 +00:00

Mail proxy: crash-proof it under overload and bizarre scenarios #1038

kayg commented

2026-10-04 11:21:37 +00:00

Author

Owner

#1038 continuation finished at 0dcfc98aa4f8da18cda3dc5d4330d36fd3e54d64; full scenario table and gate output are on #1038.

The large fixture did not complete initial sync: [63520,32,32] at 900 s; diagnostic restart also missed 180 s. A subsequent merged-server attempt returned HTTP 504 on the first account creation. Provider cause remains unestablished.

Both ordinary-fixture 30-minute windows ran with 12 clients. One-account elapsed 1845.99 s: 16,693 command cycles, 20 accepted APPEND/COPY/MOVE, 14 exact upstream and local receipts before one assertion failure. Its exact assertion was lost by the old reporter. Three-account elapsed 1841.08 s: 17,302 cycles, 20 accepted APPEND/COPY/MOVE, all 20 exact upstream/local receipts, no exception; PASS. Both retained web-session/readiness checks passed.

Read-only audits checked all 20 identities from each phase: correct local live memberships, correct Flagged state, 40 exact intentional upstream MIME copies per phase, no loss or duplication in the checked state. Three-account write distribution was [10,10,0]; no local owner/account mismatch and no foreign upstream receipts. These audits do not convert the original one-account FAIL to PASS or establish all unrun fault cases.

The reporter now emits fixed codes for known audit assertions, with a failing-first privacy regression and 12 passing Python tests. No pass/fail assertion or provider-sync code changed. No further large-fixture attempt was made, no host-quiet loop ran, and no issue was closed. READY FOR MERGE: no.

#1038 continuation finished at `0dcfc98aa4f8da18cda3dc5d4330d36fd3e54d64`; full scenario table and gate output are on #1038. The large fixture did not complete initial sync: `[63520,32,32]` at 900 s; diagnostic restart also missed 180 s. A subsequent merged-server attempt returned HTTP 504 on the first account creation. Provider cause remains unestablished. Both ordinary-fixture 30-minute windows ran with 12 clients. One-account elapsed 1845.99 s: 16,693 command cycles, 20 accepted APPEND/COPY/MOVE, 14 exact upstream and local receipts before one assertion failure. Its exact assertion was lost by the old reporter. Three-account elapsed 1841.08 s: 17,302 cycles, 20 accepted APPEND/COPY/MOVE, all 20 exact upstream/local receipts, no exception; PASS. Both retained web-session/readiness checks passed. Read-only audits checked all 20 identities from each phase: correct local live memberships, correct Flagged state, 40 exact intentional upstream MIME copies per phase, no loss or duplication in the checked state. Three-account write distribution was [10,10,0]; no local owner/account mismatch and no foreign upstream receipts. These audits do not convert the original one-account FAIL to PASS or establish all unrun fault cases. The reporter now emits fixed codes for known audit assertions, with a failing-first privacy regression and 12 passing Python tests. No pass/fail assertion or provider-sync code changed. No further large-fixture attempt was made, no host-quiet loop ran, and no issue was closed. READY FOR MERGE: no.

kayg referenced this issue

2026-10-04 13:03:14 +00:00

Mail proxy: crash-proof it under overload and bizarre scenarios #1038

kayg commented

2026-10-05 03:08:43 +00:00

Author

Owner

Deployed to production 2026-10-05 ~04:40 CEST in round 9 (269b1b51b). Includes the mail proxy (CalternalDAV, real Apple Mail acceptance PASS on the Mac VM), provider sync fixes, the stress-round fixes, #1067, #1068, #1078 and the Files upload identity repair. Staging healthy first; production healthy in 18 s; Auth 14 and Mail 17 migrations applied; change events 0/30 s; no expired leases.

Deployed to production 2026-10-05 ~04:40 CEST in round 9 (269b1b51b). Includes the mail proxy (CalternalDAV, real Apple Mail acceptance PASS on the Mac VM), provider sync fixes, the stress-round fixes, #1067, #1068, #1078 and the Files upload identity repair. Staging healthy first; production healthy in 18 s; Auth 14 and Mail 17 migrations applied; change events 0/30 s; no expired leases.

kayg closed this issue

2026-10-05 03:08:48 +00:00

Rows
Columns

Mail provider sync reports invalid responses after native Mail transfers #1037

#1037 completion report

Changes

Evidence and remaining gap

Local profile

Decisions not specified by DESIGN

Gate output

#1037 verification completion

What was verified

Files

Gates

Decisions and known gaps