debug: breadcrumbs around LMTP's non-atomic AllocateUID→Save→AppendMessage window

[0kaba0hub]

Summary

Investigating intermittent report/imap objectid smoketest failures on mdbox/sdbox (never maildir) under concurrent load. Live sandbox evidence (two independent full imaptest+smoketest rollout runs, same reproduction both times) shows a message committing a UID lower than one already committed earlier in the same UIDVALIDITY — a genuine UID monotonicity violation, not the FTS-checkpoint issue fixed by #640.

Root suspect: internal/lmtp/deliver.go is the only delivery path that does NOT use the single atomic AllocateAndAppend (used by IMAP APPEND, sieve fileinto, and MOVE/COPY). It instead:

1. AllocateUID — separate call, commits and releases the folder lock immediately
2. box.Save(...) — for mdbox/sdbox this does map lookup + refcount + possible rotation, measurably slower than maildir's flat-file write
3. AppendMessage — separate call, re-acquires the lock later

This leaves a window between steps 1 and 3, open exactly as long as step 2 takes — which is why maildir (fast Save) doesn't reproduce and mdbox/sdbox (slow Save) does.

What's confirmed vs. still open

Confirmed (live sandbox, two independent full-load repro runs): the symptom is real, backend-specific (mdbox/sdbox only), and correlates with concurrent load (imaptest + smoketest running together).

Disproved via targeted unit-test reproduction (all with a real distributed lock server, not a stubbed one):

• AllocateAndAppend concurrency across two independent userIndex instances sharing a lock server — 300 concurrent deliveries, 0 collisions
• ResetFolder's NextUID guard (if maxUID >= NextUID) — reads correctly, never regresses
• mailindex.Recreate's cross-device rename staging — already stages same-directory before the atomic rename, not the bug
• The exact deliver.go three-step pattern itself, replicated with an artificially slow middle step — 5×60 concurrent deliveries, 0 collisions

So the precise trigger is still unconfirmed — it needs the specific combination of real network/lock latency, real k8s pod scheduling, and many concurrent sub-tests that a Go unit test doesn't reproduce.

This PR

Adds DEBUG-level breadcrumbs bracketing the suspect window with a per-call correlation id (call_id in deliver.go, matched against uid in the fileindex-side logs):

• lmtp: uid allocated (right after AllocateUID)
• lmtp: body saved, committing index (right before AppendMessage, includes save_ms)
• lmtp: uid committed / lmtp: index append failed, rolling back save
• fileindex: uid allocated (inside AllocateUID, includes the folder's NextUID state)
• fileindex: committing pre-allocated uid (inside AppendMessage, includes next_uid_before — the smoking-gun field: if a commit's uid is less than the folder's next_uid_before at commit time, that's this bug caught in the act)

Purely additive logging behind the existing LOG_LEVEL=debug gate — no behavior change. Next step is a live repro run under this build to pin the exact interleaving.