Mail: 10k-message initial sync does not complete within 180 seconds #1311

Open
opened 2026-10-07 04:03:44 +00:00 by kayg · 2 comments
Owner

Steps

  1. Start the isolated TLS Dovecot fixture with 10,000 generated messages.
  2. Connect it as a Mail account in the production-build app.
  3. Wait for the initial full-history backfill.

Expected

The 10,000-message backfill completes within the 180-second Mail sync profile window, with the newest Messages available while older history continues to load (DESIGN §45).

Actual

The #1218 production-build run showed 8,880 of 10,000 Messages after 180 seconds (49.3 Messages/s). A second scaled run showed 8,440 after 350 seconds before its timeout. First content appeared after 16.517 seconds. The backfill did not complete in either run.

Evidence

kayg/calternal#1218 final report, Performance section (2026-10-07 Mail bug bash; isolated TLS Dovecot provider).

Severity: major.

## Steps 1. Start the isolated TLS Dovecot fixture with 10,000 generated messages. 2. Connect it as a Mail account in the production-build app. 3. Wait for the initial full-history backfill. ## Expected The 10,000-message backfill completes within the 180-second Mail sync profile window, with the newest Messages available while older history continues to load (DESIGN §45). ## Actual The #1218 production-build run showed 8,880 of 10,000 Messages after 180 seconds (49.3 Messages/s). A second scaled run showed 8,440 after 350 seconds before its timeout. First content appeared after 16.517 seconds. The backfill did not complete in either run. ## Evidence `kayg/calternal#1218` final report, Performance section (2026-10-07 Mail bug bash; isolated TLS Dovecot provider). Severity: major.
Author
Owner

Change committed as e4eea7644: one json_each(?) lookup resolves thread keys for a fetched window, page-local maps preserve sequential thread merging, and thread-key upserts run in 300-row batches inside the existing transaction. The IMAP window size and message assertions are unchanged.

Measured results:

  • Local synthetic 10k profile_full_history, three interleaved runs: median wall 21.814 s before → 14.350 s after (-34.2%); median worker CPU 10.45 → 9.46 s (-9.5%); peak RSS median/max changed by about +0.3 MiB. The local host load fell during the samples, so this A/B is directional.
  • One real TLS 10k fixture completed in 39.292 s (254.50 messages/s), first content 16.046 s and first paint 16.845 s. Historical #1218 reached 8,880/10,000 in 180 s (~49.3 messages/s), so the successful local run is about 5.2x that observed throughput. The 10k run later stopped in its UI follow-up at a stale category assertion; #1328 corrected the flow.
  • Three local 2k real-TLS runs completed backfill in 28.696 / 25.824 / 18.195 s. Median per-page provider p50/p95: 4/22 ms; Index commit p50/p95: 20/204 ms. Commit time dominated provider time. Max commit samples reached 2.2 s during high host load.

A second 10k real-TLS attempt under local host load failed after a passive WAL checkpoint took 22.77 s and the Mail cache step returned a storage error. The perf VM was occupied when I tried perf-run, so the candidate A/B remains local and noisy. #1330 tracks the subsequent loaded thread-body timeout. I did not get a controlled perf-VM flamegraph or a stable end-to-end repeat in this round.

Change committed as `e4eea7644`: one `json_each(?)` lookup resolves thread keys for a fetched window, page-local maps preserve sequential thread merging, and thread-key upserts run in 300-row batches inside the existing transaction. The IMAP window size and message assertions are unchanged. Measured results: - Local synthetic 10k `profile_full_history`, three interleaved runs: median wall 21.814 s before → 14.350 s after (-34.2%); median worker CPU 10.45 → 9.46 s (-9.5%); peak RSS median/max changed by about +0.3 MiB. The local host load fell during the samples, so this A/B is directional. - One real TLS 10k fixture completed in 39.292 s (254.50 messages/s), first content 16.046 s and first paint 16.845 s. Historical #1218 reached 8,880/10,000 in 180 s (~49.3 messages/s), so the successful local run is about 5.2x that observed throughput. The 10k run later stopped in its UI follow-up at a stale category assertion; #1328 corrected the flow. - Three local 2k real-TLS runs completed backfill in 28.696 / 25.824 / 18.195 s. Median per-page provider p50/p95: 4/22 ms; Index commit p50/p95: 20/204 ms. Commit time dominated provider time. Max commit samples reached 2.2 s during high host load. A second 10k real-TLS attempt under local host load failed after a passive WAL checkpoint took 22.77 s and the Mail cache step returned a storage error. The perf VM was occupied when I tried `perf-run`, so the candidate A/B remains local and noisy. #1330 tracks the subsequent loaded thread-body timeout. I did not get a controlled perf-VM flamegraph or a stable end-to-end repeat in this round.
Author
Owner

One later 10k real-TLS retry under high local load failed before completion: the passive WAL checkpoint took 22.768 s, then the Mail cache step returned error_kind=storage and the overall sync was reported as a transport error. This is tracked separately in #1337; the first 10k candidate run completed in 39.292 s. I did not repeat it on the busy perf VM.

One later 10k real-TLS retry under high local load failed before completion: the passive WAL checkpoint took 22.768 s, then the Mail cache step returned `error_kind=storage` and the overall sync was reported as a transport error. This is tracked separately in #1337; the first 10k candidate run completed in 39.292 s. I did not repeat it on the busy perf VM.
Commenting is not possible because the repository is archived.
No labels
No milestone
No project
No assignees
1 participant
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
kayg/calternal-v0#1311
No description provided.