Skip to content

Handle clock stepping back in mailbox prune - #2006

Open
Manuel1234477 wants to merge 2 commits into
payjoin:masterfrom
Manuel1234477:fix/mailroom-prune-clock-skew
Open

Manuel1234477 wants to merge 2 commits into
payjoin:masterfrom
Manuel1234477:fix/mailroom-prune-clock-skew

Conversation

@Manuel1234477

@Manuel1234477 Manuel1234477 commented Oct 23, 2026 •

Copy link
Copy Markdown

next_prune() does created.elapsed().expect("system clock moved back"). If the clock gets stepped back after a mailbox was written (NTP correcting the time on a box without an RTC is the usual case), that timestamp is in the future and elapsed() errors.

prune() runs on every post and read via has_capacity(), so until the clock catches up every mailbox request panics. The background prune task also panics and never comes back.

This treats a future timestamp as zero elapsed instead of panicking. The entry still expires normally once the clock passes created + ttl.

Added test_prune_with_future_timestamp, which panics on master and passes with the change.

next_prune() called created.elapsed().expect(...), which panics when a
mailbox timestamp is later than the current time. That happens if the
system clock is stepped back after a mailbox was written, e.g. NTP
correcting the time on a host without an RTC. Timestamps loaded from
file metadata at startup can be affected the same way.

prune() runs on every post and read through has_capacity(), so while
the clock is behind, every mailbox request panics. The background
prune task panics too and is never restarted.

Treat a future timestamp as zero elapsed time instead. The entry still
expires once the clock passes created + ttl.

@codaMW codaMW left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

tACK 70aec62

Reviewed the clock-step prune panic fix, including a mutation to confirm the test pins the exact crash.

The bug: next_prune computes ttl minus created.elapsed(), and SystemTime::elapsed() returns Err whenever the stored timestamp is in the future relative to now. That is precisely what a backward clock step produces (NTP correction, suspend or resume, VM snapshot restore): an entry written before the step now sits in the future. The old expect("system clock moved back") turned that into a panic. It is reached from prune(), which runs both in the request path via maybe_prune and in the background task via spawn_background_prune (there wrapped in expect("disk storage failed")), so a single backward step took out pruning.

The fix: unwrap_or(Duration::ZERO) treats a future timestamp as zero elapsed, so next_prune returns the full ttl and the entry is handled as if just written. That is the right semantics. The entry is not yet expired, so it should stay, and the scheduler simply waits a full ttl while the clock catches up.

Scope check: I went through the rest of the mailroom time handling. next_prune was the only fallible elapsed() guarded by an expect. gateway_prober uses Instant, which is monotonic and cannot error, and metrics.rs has a separate expect for a pre-1970 clock, which is a different condition, not a backward step. So this is the complete fix for the backward-step panic class. The prune() loop itself compares created + ttl < now via SystemTime ordering, which does not panic under a backward clock and just prunes less until the clock catches up, consistent with the fix.

Tested on 70aec62, repo-pinned nightly, --all-features:

  • test_prune_with_future_timestamp: pass

The test pushes the stored insert_order timestamps 60s into the future to simulate the clock stepping back after a write, asserts prune() returns ttl rather than panicking and that the entry is retained (len 1), then posts a second payload and asserts len 2, proving the db keeps serving while the clock catches up.

Mutation: restoring created.elapsed().expect("system clock moved back") makes the test panic at files.rs:491 with SystemTimeError(59.998...s), i.e. the precise crash the fix removes. So the test is load-bearing.

One optional, non-blocking thought: unwrap_or(Duration::ZERO) swallows the SystemTimeError silently. A trace or debug log on the error path would let an operator notice a genuine backward step, though in the prune hot path that is a judgment call and I would not hold the PR for it.

@caarloshenriq caarloshenriq left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ACK 70aec62

Reproduced locally: the new test passes, and panics at files.rs:491 with the original expect restored. Treating a future timestamp as zero elapsed is the right call, since the entry is kept and nothing expires early

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants