Test: derive forkless bgsave TTL deadlines from when each EXPIRE ran

[madolson]

TTL expiration during forkless bgsave sets TTLs with 1200 synchronous EXPIRE round trips, then computes every expiry deadline from a timestamp captured before that loop starts, so its model of when key i dies lags reality by however long the loop took. For keys where i % 10 == 0 the built-in slack is exactly one second, so any environment slower than about 0.9 ms per round trip fails the "must be gone" assertion on a key that is still legitimately alive. This records each key's deadline as its own EXPIREs are issued, and re-samples the clock per key in the verification loop instead of once per outer pass over up to 1200 EXISTS calls. Test-only; the server was expiring correctly the whole time.

Details

Upstream: valkey-io/valkey#4611. Introduced by acba5ddd0 "Forkless Save (#4460)", which added the test.

Problem

tests/integration/rdb.tcl:1014 took set start_time [clock milliseconds] before the loop at 1015-1021 that issues 100 keys x 12 prefixes = 1200 synchronous EXPIRE calls with ttl = $i/10 + 1 (integer division, 1016). The gone-threshold at 1062 was elapsed_time > $i/10.0 + 2, measured from start_time.

Assumed deadline: start_time + i/10 + 1. Real deadline: t_expire(i) + floor(i/10) + 1, where t_expire(i) is the wall time from start_time until key i's EXPIREs execute, 12 * i round trips in. So

margin(i) = frac(i/10) + 1 - t_expire(i)

For i % 10 == 0 the fractional term is 0 and the whole margin is 1 s - t_expire(i).

Second, independent flaw: elapsed_time was sampled once per outer pass at 1053 and then reused across up to 1200 EXISTS commands at 1055-1077. That one biases the opposite branch ("not yet expired, must exist"), so it is not what CI hit, but it fails the same way.

Reproduction

The knob is per-command latency. appendfsync always makes every EXPIRE wait on an fsync, which pushes the round trip from ~34 us to ~2.8 ms and blows the 1 s budget deterministically. Both configs are set globally by --config, so start_server's {forkless-infrastructure-enabled yes save ""} overrides still apply.

./runtest --single integration/rdb --loops 5 --config appendonly yes --config appendfsync always

Instrumented, the EXPIRE loop takes 3.36 s instead of 0.041 s:

REPRO42: t_expire_total=0.041s  appendonly=no  appendfsync=everysec
REPRO42: t_expire_total=3.364s  appendonly=yes appendfsync=always

And at the failure the key is not stuck, it simply has TTL left, because its EXPIRE ran 1.3 s after start_time:

REPRO42 FAIL i=40 test_elapsed=6.002s test_assumed_deadline=5s pttl=297ms => real_deadline=6.299s

That is what rules out a forkless-save defect: PTTL returns a live, positive TTL. Lost expire metadata would make keys immortal and fail at i = 0 on every platform every run, not 1 in 7 daily runs.

Runs

Before, 5/5 fail, same assertion and same relative line 56 as the CI job:

=== BEFORE FIX, 5 loops, appendfsync always ===
Expected '1' to be equal to '0' (context: type eval line 56 cmd {assert_equal [r exists before_${i}] 0} proc ::test)
Expected '1' to be equal to '0' (context: type eval line 56 cmd {assert_equal [r exists before_${i}] 0} proc ::test)
Expected '1' to be equal to '0' (context: type eval line 56 cmd {assert_equal [r exists before_${i}] 0} proc ::test)
Expected '1' to be equal to '0' (context: type eval line 56 cmd {assert_equal [r exists before_${i}] 0} proc ::test)
Expected '1' to be equal to '0' (context: type eval line 56 cmd {assert_equal [r exists before_${i}] 0} proc ::test)
Test Summary: 0 passed, 5 failed

After, 5/5 pass under the same knob, and 5/5 without it:

=== AFTER FIX, 5 loops, appendfsync always ===
Test Summary: 5 passed, 0 failed

=== AFTER FIX, 5 loops, no knob ===
Test Summary: 5 passed, 0 failed

Full file, unmodified invocation:

$ ./runtest --single integration/rdb --loops 5
Test Summary: 265 passed, 0 failed

Slack preserved

The rewrite keeps the original tolerances, just measured against a correct per-key deadline. deadline($i) is sampled before the 12 EXPIREs, so it sits at or below every real deadline, which is the safe direction for both branches. The exist branch keeps the original 1 s margin as $now + 1000 < $deadline($i); the gone branch keeps 2 s as $now > $deadline($i) + 2000.

Alternative rejected

Switching the loop to PEXPIREAT start_time + ttl*1000 also makes the arithmetic exact, but on a slow machine the 1 s TTLs for i = 0..9 land in the past and those keys are deleted before bgsave runs, so the test would stop covering keys-with-TTL during a forkless snapshot in exactly the environments that flake.

Base branch

madolson/valkey-agents unstable is 66 commits behind valkey-io/valkey unstable and has no forkless save at all (grep -c forkless src/rdb.c returns 0), so this targets upstream-unstable-d6415e766, an unmodified copy of valkey-io/valkey@d6415e766, following the pattern of #15.

This was generated by AI but verified, with love, by a human.