Skip to content

fix: list the entries of the fake in the order of the writes - #80

Merged
sstriker merged 1 commit into
mainfrom
fix/conformance-fake-order
Nov 15, 2026
Merged

sstriker merged 1 commit into
mainfrom
fix/conformance-fake-order

Conversation

@sstriker

Copy link
Copy Markdown
Contributor

The flaky test

scripts/conformance.test.sh failed one time and then passed six times on the same code.
The case was missing-tool. Step 4 of scripts/conformance.py reported:

list is not newest first: ['mem-fake-0001', 'mem-fake-0002']

The cause

The fake server (scripts/conformance-fake-server.py) sorted its list by created.
created was the wall clock in whole seconds, with the sequence number after it. Step 2
writes the decision and then the handoff. When the wall clock reads an earlier second at
the second write, the handoff gets the earlier time. Then the list shows the handoff
second.

The wall clock of the WSL2 machine that showed the failure steps back:

  • A sampler compared time.time() with time.monotonic() for 100 seconds, two times.
    Each time it recorded 3 steps back, about 32 seconds apart. Each step was between 0.80
    and 0.83 seconds.
  • The system journal of that machine holds 52 lines "Time jumped backwards" and 610 lines
    "Clock change detected" for 14 November, 17:39 to 22:57.

How I reproduced the failure

Both reproductions used the code before this change.

  1. On the clock of the machine. A driver wrote one entry to the fake and then called
    list, again and again, for 100 seconds. It made 17943 writes. 68 lists did not show
    the newest entry first. They started at 3 writes whose created was one second before
    the created of the write before: 22:00:03 then 22:00:02, 22:00:35 then 22:00:34,
    22:01:06 then 22:01:05.
  2. On a clock that a wrapper controls. The wrapper made time.gmtime() read one hour
    ahead at the first read of the run, and correct after that. conformance.py against
    the fake reported the line above and 6 of 7 steps passed, 175 checks; FAILED: 4.

The fix

The record of the fake grows only at its end. The list is now that order, last write
first. No clock decides it. created is now a time only, without the sequence number.

After the fix, the same driver made 18201 writes in 100 seconds, and all lists were in
the correct order. In those 100 seconds the sampler recorded 3 steps back.

The new case

clock-back makes the fake stamp the first entry one hour ahead and the second entry at
the correct time. The test expects the full run to pass (7 of 7 steps passed). Thus
make check makes the step back on each run, and CI finds an order that depends on the
wall clock without a person.

With the list sorted by created and then id, as before, the test reported:

clock-back: exit 1 ending 6 of 7 steps passed; FAILED: 4; wanted exit 0 ending 7 of 7 steps passed holding anything
    FAIL: list is not newest first: ['mem-fake-0001', 'mem-fake-0002']
1 conformance test(s) failed

No other case failed in that run.

What is still open

  • I did not find which process sets the clock of that machine back.
  • No record shows the wall clock at the moment of the first failure. The order in the
    report is possible only when the later write has the earlier created.
  • conformance.py reads lease_until on the wall clock of the server. Its comments give
    the margins. I did not test those margins against a clock step.

The adversarial pass

No adversarial pass ran, because the change is a test script of a few lines.

Posted by Claude on behalf of @sstriker

🤖 Generated with Claude Code

https://claude.ai/code/session_01D5DyJRpu5ned5y3d92U7Ts

`scripts/conformance.test.sh` failed one time, in the case `missing-tool`. Step 4 of
`scripts/conformance.py` reported:

    list is not newest first: ['mem-fake-0001', 'mem-fake-0002']

The cause

The fake sorted its list by `created`. `created` was the wall clock in whole seconds,
with the sequence number after it. Step 2 writes the decision and then the handoff. When
the wall clock reads an earlier second at the second write, the handoff gets the earlier
time. Then the list shows the handoff second.

The wall clock of the WSL2 machine that showed the failure steps back. A sampler compared
`time.time()` with `time.monotonic()` for 100 seconds, two times. Each time it recorded 3
steps back, about 32 seconds apart. Each step was between 0.80 and 0.83 seconds. The
system journal of that machine holds 52 lines "Time jumped backwards" and 610 lines
"Clock change detected" for 14 November, 17:39 to 22:57.

The reproduction, on the code before this change

1. On the clock of the machine. A driver wrote one entry to the fake and then called
   `list`, again and again, for 100 seconds. It made 17943 writes. 68 lists did not show
   the newest entry first. They started at 3 writes whose `created` was one second
   before the `created` of the write before: 22:00:03 then 22:00:02, 22:00:35 then
   22:00:34, 22:01:06 then 22:01:05.
2. On a clock that a wrapper controls. The wrapper made `time.gmtime()` read one hour
   ahead at the first read of the run, and correct after that. `conformance.py` against
   the fake reported the line above and "6 of 7 steps passed, 175 checks; FAILED: 4".

The fix

The record of the fake grows only at its end. The list is now that order, last write
first. No clock decides it. `created` is now a time only, without the sequence number.

After the fix, the same driver made 18201 writes in 100 seconds and all lists were in
the correct order. In those 100 seconds the sampler recorded 3 steps back.

The new case

`clock-back` makes the fake stamp the first entry one hour ahead and the second entry
at the correct time. The test expects the full run to pass. Thus `make check` makes the
step back on each run, and CI finds an order that depends on the wall clock.

With the list sorted by `created` and then `id`, as before, the test reported:

    clock-back: exit 1 ending 6 of 7 steps passed; FAILED: 4; wanted exit 0 ending 7 of 7 steps passed holding anything
        FAIL: list is not newest first: ['mem-fake-0001', 'mem-fake-0002']
    1 conformance test(s) failed

Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01D5DyJRpu5ned5y3d92U7Ts
Copilot AI balanced review requested due to automatic review settings November 14, 2026 22:14

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Copilot was unable to review this pull request because the user who requested the review has insufficient remaining quota. Try requesting a review at a lower effort level.

@sstriker
sstriker merged commit be47b1c into main Nov 15, 2026
10 checks passed
@sstriker
sstriker deleted the fix/conformance-fake-order branch November 15, 2026 07:24
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.

2 participants