Skip to content

driver: record what a differential run found - #593

Merged
MarcusKainth merged 1 commit into
mainfrom
driver/diff-record
Sep 25, 2026
Merged

MarcusKainth merged 1 commit into
mainfrom
driver/diff-record

Conversation

@MarcusKainth

Copy link
Copy Markdown
Owner

What this changes, and why

clickdoom native diff --record PATH appends one JSON line per run saying what
the run found and what it cost. A nightly job records one line per main commit
and compares each with the one before it, so a commit that moves the first
refusal earlier, adds a divergence or slows the tic statement's analysis gets
noticed on the commit that did it.

The line carries: commit, clickhouse, runner_cpu, first_refused_tic,
first_refused_bits, first_divergent_tic, first_divergent_field,
compared_through, compared_tics, stage1_analysis_s, stage2_analysis_s,
tic_ms_p50, tic_ms_p95, tics, run_id (GITHUB_RUN_ID) and error.
A field the run could not tell is null. A run that stops at a refusal compares
nothing, and its compared_through is null, which tells it apart from a run
that compared and agreed.

The residents already run under their own query ids, so the analysis times are
read from system.query_log by those ids. The server writes a statement's
QueryFinish row after it has answered the close, and a single SYSTEM FLUSH LOGS missed it on the first live run, so the read flushes and polls for up to
30 s. The first tic is left out of the tic percentiles.

What the command prints and its exit codes are unchanged. compare is split
from report so the record and the exit code read the same result.

Evidence

Throwaway container clickhouse/clickhouse-server:26.8.2.7 on port 18139, Apple
M5 Max, no machine lock (a correctness run).

The live suite, with the new assertions:

$ CLICKHOUSE_HTTP_PORT=18139 CLICKHOUSE_PASSWORD=clickdoom cargo nextest run --release \
    --features clickhouse-tests -p clickdoom-driver --test-threads 2 -E 'binary(native_diff_live)'
        PASS [  20.663s] (1/2) clickdoom-driver::native_diff_live a_differential_run_reports_the_first_field_that_differs
        PASS [  23.289s] (2/2) clickdoom-driver::native_diff_live a_tic_that_refuses_stops_before_the_field_comparison
     Summary [  23.289s] 2 tests run: 2 passed, 0 skipped
exit=0

The same suite with the record::append call replaced by let _ = (path, found);,
restored afterwards with git checkout HEAD -- driver/src/cli/native/diff.rs:

exit=100
    FAIL [  11.745s] (1/2) clickdoom-driver::native_diff_live a_differential_run_reports_the_first_field_that_differs
    panicked at driver/tests/native_diff_live.rs:96:41:
    the record is written: Read { path: ".../clickdoom_native_diff_82297.jsonl", source: Os { code: 2, kind: NotFound, ... } }
    FAIL [  22.125s] (2/2) clickdoom-driver::native_diff_live a_tic_that_refuses_stops_before_the_field_comparison
    panicked at driver/tests/native_diff_live.rs:223:41:
    the record is written: Read { path: ".../clickdoom_native_diff_refusal_82298.jsonl", source: Os { code: 2, kind: NotFound, ... } }

The command against a full probe trace regenerated from this tree
(refemu probe ... --stop-at halt -n 4000000000, 2172 rows), the two runs the
nightly makes: one to find the refusal, one over the span before it.

$ clickdoom native load --fresh --port 18139 --database regress --password clickdoom
load exit=0
$ clickdoom native diff 2000 --probe probe.9a6a47d01119.tsv --record run1.jsonl --port 18139 --database regress ...
clickdoom: error: tic 275 unresolved: CHASE_STUCK
run1 exit=3
{"commit":"3ef55ff88993d70ef7206fadfe7a490997fa30ad","clickhouse":"26.8.2.7","runner_cpu":"Apple M5 Max","first_refused_tic":275,"first_refused_bits":"unresolved: CHASE_STUCK","first_divergent_tic":null,"first_divergent_field":null,"compared_through":null,"compared_tics":null,"stage1_analysis_s":1.194395,"stage2_analysis_s":0.358287,"tic_ms_p50":50.946709,"tic_ms_p95":89.713291,"tics":2000,"run_id":null,"error":null}

$ clickdoom native diff 274 --probe probe.9a6a47d01119.tsv --record run2.jsonl --port 18139 --database regress ...
no divergence: every field agrees over the 273 tics both sides hold
run2 exit=0
{"commit":"3ef55ff88993d70ef7206fadfe7a490997fa30ad","clickhouse":"26.8.2.7","runner_cpu":"Apple M5 Max","first_refused_tic":null,"first_refused_bits":null,"first_divergent_tic":null,"first_divergent_field":null,"compared_through":274,"compared_tics":273,"stage1_analysis_s":1.269686,"stage2_analysis_s":0.352883,"tic_ms_p50":46.741416,"tic_ms_p95":87.144584,"tics":274,"run_id":null,"error":null}

Unit tests, lint and purity, statuses captured before any pipe:

$ cargo test -p clickdoom-driver --lib
test result: ok. 116 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
unit exit=0
$ cargo clippy -p clickdoom-driver --all-targets --all-features -- -D warnings
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 15.76s
$ ./scripts/check_purity.sh >/dev/null 2>&1; echo "purity exit=$?"
purity exit=0
$ cargo fmt --all -- --check >/dev/null 2>&1; echo "fmt exit=$?"
fmt exit=0

Invariants

PUR-10 and PUR-12. The percentiles and the wait for system.query_log are
reporting on timings the driver already measured with Monotonic. Nothing they
produce reaches a statement or a value the simulation computes, and the
analysis times are read back from the server's own log after the session has
closed. check_purity.sh passes, above.

Spec impact

  • None. No contract in SPEC.md is touched

NATIVE.md does not describe native diff's flags, and the parity behaviour it
does describe is unchanged.

Checks

  • make gates. Not run under that name. native_diff_live, the driver's
    unit tests, clippy, fmt and check_purity.sh were run by exit code, above
  • make native-smoke, unaffected: it renders a frame and does not diff
  • No AI attribution trailers in the commits

Written mostly by Claude Opus 5.5.

@github-actions github-actions Bot added the area: driver The client loop that ticks the batch statement and blits frames label Sep 25, 2026
`clickdoom native diff --record PATH` appends one JSON line per run: the
commit, the server version, the CPU model, the first refused tic and the
bits it named, the first divergent tic and field, the last tic compared
and how many both sides held, each simulation statement's
QueryAnalysisMicroseconds, the median and 95th percentile tic time, the
tic count and GITHUB_RUN_ID when it is set.

A nightly job appends these lines per main commit and compares each one
with the one before it, so the line has to say which of refusal,
divergence and agreement the run found, with nulls where the run could
not tell: a run that stopped at a refusal compared nothing, and its
compared_through is null.

The analysis times come from system.query_log, keyed by the query ids the
session already gives both statements. The server writes a statement's
QueryFinish row after it has answered the close, so a single flush can
miss it; the read flushes and polls for up to 30 s. The first tic is left
out of the tic percentiles because it pays for the analysis, which is
recorded on its own.

The comparison is split from the printing so the record and the exit
code read the same result. What the command prints and its exit codes
are unchanged.
@MarcusKainth
MarcusKainth marked this pull request as ready for review September 25, 2026 13:43
@MarcusKainth
MarcusKainth merged commit 557f5b1 into main Sep 25, 2026
20 checks passed
@MarcusKainth
MarcusKainth deleted the driver/diff-record branch September 25, 2026 13:43
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

area: driver The client loop that ticks the batch statement and blits frames

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant