Skip to content

a replayed timestamp is only nearly reproducible, because replayEvent sets a clock baseline that then advances with wall time #1217

Description

@scttfrdmn

What

replayEvent sets the simulated clock to the recorded event's timestamp and then lets it advance with
wall time
, so any value a handler renders from TimeController.Now() is reproduced on replay only to
within the wall-clock latency of the replay path. When the recorded and replayed reads fall either side
of a second boundary, the rendered second differs and the replay reports a difference.

Observed on CI for PR #1216 — a documentation-only change touching docs/services.md and
CHANGELOG.md and no Go file — in both Test (Go 1.26) and Test (Go 1.27):

--- FAIL: TestReplayBodyDiff_ARecordedListingReplaysByteIdentically (0.01s)
    replay_body_diff_test.go:383:
        seq=3 op=ListBuckets
        response_body/ListAllMyBucketsResult/Buckets/Bucket[3]/CreationDate:
          2026-09-20T00:36:20Z -> 2026-09-20T00:36:21Z (major)

The mechanism, exactly

TimeController stores a (simBaseline, wallBaseline) pair and Now() returns
simBaseline + (time.Since(wallBaseline) * scale) (types.go:253-258). SetTime resets both
baselines (:263-269). replay.go:417-418 calls SetTime(event.Timestamp) before dispatching the
event. So:

  • Recording: the S3 handler reads p.tc.Now() at s3_plugin.go:519, and the event's Timestamp
    is stamped elsewhere on the request path. The two differ by however long that path takes — call it
    δ₁.
  • Replay: SetTime(event.Timestamp) runs, then the handler reads Now(), which is now
    event.Timestamp + δ₂ where δ₂ is the wall time the replay dispatch itself took.

CreationDate is rendered RFC3339 with no fractional seconds
(s3_list_buckets.go:184), so the recorded and replayed strings agree whenever
event.Timestamp − δ₁ and event.Timestamp + δ₂ land in the same second, and disagree by one second
whenever they straddle a boundary. With four buckets in the fixture the flake probability is roughly
4 × (δ₁+δ₂)/1s per run — small, invisible for months, and independent of what the change under test
touched.

The property this actually breaks

The test is the passing half of #817's fourth criterion — "a recorded run whose bodies carry no minted
value replays with no difference at all"
— and its own doc comment states the premise that is not
quite true: "their creation dates — rendered from the simulated clock, which replayEvent sets to the
recorded event's timestamp"
. SetTime sets a baseline, not a value. So a timestamp is not a
reproducible value on replay; it is a nearly-reproducible one, and CLAUDE.md's ## Testing rule —
"No test should depend on network access, real AWS, or wall-clock time" — is violated by every test
that asserts a replayed timestamp, not only this one.

This is adjacent to #856's debt 3 (state_hash_after is not invariant) but distinct: a timestamp is
not a minted identifier, and the ID-tape design recommended there does not cover it. A frozen clock
does, and would make any record carrying a timestamp hash identically on replay.

Why this matters

A red test that is not a real signal is the one failure mode substrate's whole architecture exists to
remove — CLAUDE.md puts it first in the payoff list: "no test flakes (a red test is a real signal,
not timing noise)."
This one failed a docs-only PR, which is the worst version of it: the reviewer's
first hypothesis is their own change, and the evidence points nowhere near it.

It is also a genuine fidelity claim, not only a test defect. Substrate advertises that a recorded run
replays identically; today a recorded run replays identically except for timestamps, usually.
Anyone building a regression fixture out of a recorded run — which doc.go offers as a feature — is
exposed to the same one-in-N failure, off CI, with no test to point at.

Acceptance criteria

  • The clock is frozen for the duration of an event's replay, so every Now() read while
    replaying one event returns exactly event.Timestamp. SetScale(0) already does this
    (types.go:283-291) — freeze on entry to replayEvent and restore the recorded scale after, or
    give TimeController an explicit frozen mode if a zero scale has other readers.
  • A recorded run containing a timestamp-rendering operation replays with zero differences
    across a boundary: a test that sets the clock so the recorded read lands within a millisecond of
    a second boundary and asserts the replay still matches. Today that test fails deterministically,
    which is the point — the current flake cannot be reproduced on demand and so cannot be regression
    tested.
  • TestReplayBodyDiff_ARecordedListingReplaysByteIdentically's doc comment is corrected: it states
    that replayEvent sets the clock to the recorded timestamp, where in fact it sets a baseline that
    advances.
  • Every other replay test that asserts a timestamp is checked for the same exposure, and the result
    recorded.
  • docs/services.md's replay documentation, and doc.go where it offers a recorded run as a
    regression fixture, state that a replayed timestamp is exactly the recorded one — once it is.

Provenance

Entirely in-tree; no AWS behaviour is at issue. emulator/types.go:253-258 (Now() advances from the
baseline), :263-269 (SetTime resets both baselines), :283-291 (SetScale, which captures the
current simulated time and is the freeze mechanism); emulator/replay.go:417-418 (the SetTime call);
emulator/s3_plugin.go:519 (the p.tc.Now() read); emulator/s3_list_buckets.go:184 (RFC3339 with no
fractional seconds); emulator/replay_body_diff_test.go:369-384 (the test and the doc comment).

The failing run is
https://github.com/scttfrdmn/substrate/actions/runs/35479145414 on PR #1216. The same wall-clock
argument is written out in emulator/ec2_snapshot_control.go's doc comment (#715), which rejected a
duration seed for exactly this reason: "[TimeController.Now] advances with wall time from its
baseline."

Line citations are from the tree at the commit this issue was filed against.

Activity

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    area: replayIssues relating to the replay component

    Projects

    No projects

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions