Repository navigation
Handle clock stepping back in mailbox prune - #2006
Manuel1234477 wants to merge 2 commits into
Conversation
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
left a comment
There was a problem hiding this comment.
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
left a comment
There was a problem hiding this comment.
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
next_prune()doescreated.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 andelapsed()errors.prune()runs on every post and read viahas_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.