From f78069ad4d0f711a133263bf2bc8986bb189d2f4 Mon Sep 17 00:00:00 2001 From: Sander Striker Date: Sat, 14 Nov 2026 23:07:40 +0100 Subject: [PATCH] fix: list the entries of the fake in the order of the writes `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 Claude-Session: https://claude.ai/code/session_01D5DyJRpu5ned5y3d92U7Ts --- scripts/conformance-fake-server.py | 13 +++++++++++-- scripts/conformance.test.sh | 4 ++++ 2 files changed, 15 insertions(+), 2 deletions(-) diff --git a/scripts/conformance-fake-server.py b/scripts/conformance-fake-server.py index 51d242e0..8df47df2 100644 --- a/scripts/conformance-fake-server.py +++ b/scripts/conformance-fake-server.py @@ -27,6 +27,11 @@ reindex-forgets reindex drops the ledger silent nothing is ever answered +One value is not a defect of the server. It is a clock that was set back, and a run with +it must pass: + + clock-back the wall clock reads an hour ahead at the first write, and is right at the next + Not part of the product: it exists to be imperfect on request. """ @@ -121,8 +126,11 @@ def __init__(self): # ---- entries def entries(self, kind=None): + """The entries, newest first: the record grows only at its end, so that is the + order of the writes, last first. Not the order of `created`: a wall clock that + steps back (WSL2's does when it resyncs) dates a later write before an earlier one.""" es = [e for e in self.state["entries"] if kind is None or e["type"] == kind] - return sorted(es, key=lambda e: e["created"], reverse=True) + return es[::-1] def hit(self, e, body=False): h = {k: e[k] for k in ("id", "domain", "type", "title", "summary", "classification")} @@ -167,6 +175,7 @@ def write(self, a): if "body" not in a: raise Refused("body is required") self.state["seq"] += 1 + ahead = 3600 if FLAW == "clock-back" and self.state["seq"] == 1 else 0 body = a["body"] first = next((l for l in body.splitlines() if l.strip()), "") e = { @@ -177,7 +186,7 @@ def write(self, a): "summary": a.get("summary") or first, "body": body, "author": "human:fake:owner", - "created": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()) + f"{self.state['seq']:04d}", + "created": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime(time.time() + ahead)), "classification": "internal" if FLAW == "write-ignores-label" else a.get("classification") or "internal", } self.state["entries"].append(e) diff --git a/scripts/conformance.test.sh b/scripts/conformance.test.sh index 3513d025..3727ca61 100644 --- a/scripts/conformance.test.sh +++ b/scripts/conformance.test.sh @@ -38,6 +38,7 @@ run() { run whole '' --operator "python3 $fake operator" --drop-index "python3 $fake operator drop-index" run surface '' +run clock-back clock-back --operator "python3 $fake operator" --drop-index "python3 $fake operator drop-index" run missing-tool missing-tool --operator "python3 $fake operator" run write-ignores-label write-ignores-label run t0-forgets t0-forgets --operator "python3 $fake operator" @@ -82,6 +83,9 @@ expect() { # a conformant server passes, whole and surface-only expect whole 0 '7 of 7 steps passed' expect surface 0 '5 of 7 steps passed; not run: 6, 7' +# and so does one whose wall clock was set back between two writes: a list is in the order +# of the writes, whatever times the entries carry +expect clock-back 0 '7 of 7 steps passed' # and each defect is reported at the step whose claim it breaks, the rest still running expect missing-tool 1 '6 of 7 steps passed; FAILED: 1' 'tools/list lacks heartbeat' expect write-ignores-label 1 '1 of 7 steps passed; not run: 6, 7; could not run: 3, 4, 5; FAILED: 2' "write at public came back 'internal'"