Skip to content

Instrument gaps found in the 2026-11 pass: one fixed mid-pass, three deferred to the next pass #555

Open

Description

@tae898

A read-only audit of the 147 rows the 2026-11 paper pass wrote on mini so far (stages qC01 to qC08, comparators only, engine pin e85469273, harness 20eea4b94) found four instrument gaps. One is fixed in the middle of the pass because the fix is additive and outside every timer (the dense lane's missing close phase). The others are deferred on purpose: fixing them now would change how a figure is measured between rounds of the same pass. They are listed here so the next pass (and any later benchmark on this instrument) collects every number from its first round. Follow-up to #352.

# What is missing Rows affected in pass 1 Cause Fix for the next pass Why not now
1 dense lane (l3d): memory and disk after queries (mem_queries_*, mem_idle_*, disk_queries_*) and the JVM working set after GC all 12 OK dense rows (mem_probe_phases=load,index_build,warmup) memory_probe.phases_for_mark takes queries and idle from the close-start mark; l3d_dense.py never enters _beat.phase("close") (the other lanes do: l1_tpc.py, l2_graph.py, e2_hybrid.py, l3_sparse.py, l4_tsbs.py) fixed in this pass from dense round 2 (stage qC12) on; round 1 lacks these fields, so this figure has one round fewer (fixed)
2 exact memory peak per phase: mem_probe_peak_reset=False, mem_probe_peak_kind=sampled-0.25s 123 of 123 OK rows PeakFile in memory_probe.py opens the container's cgroup memory.peak read-write to reset it per phase; on mini the file is root-owned and the runner is not root host side: give the runner write access to memory.peak (cgroup delegation or a small root helper), then per-phase peaks are exact changes the measurement method mid-pass; needs a host setting. The whole-cell peak is exact today; per-phase peaks are the 0.25 s sampled maximum, and the page says so
3 JVM working set for Neo4j inside the composed Qdrant + Neo4j stack (jvm_* fields) 6 of 6 OK composed_qdrant_neo4j cross-model rows (server_jvm empty) the composed stack's Neo4j is not registered as a JVM server for the probe (MongoDB's mongot is, and carries the fields); cause not traced further register the composed stack's Neo4j JVM with the probe registering it adds the probe's forced GCs at phase marks for Neo4j, which could shift Neo4j's timed figures between rounds
4 memory and disk after the index build for the documents (l1tpc) and cross-model (e2) lanes 35 OK documents rows and 33 OK cross-model rows have the ingest_s / index_s split but no index_build phase no post-build marker between the two timers in those lanes a phase marker between the ingest and the index timers (as l3d has post-build) for JVM engines the probe's forced GC would land right before the index timer and could change index_s

Smaller items, no rerun needed:

  • oltp_total_s is written only by l2_graph.py, so it is empty on the documents OLTP rows; it feeds no table column, but page_check lists it.
  • *_wal_mib is empty on the SurrealDB served rows and a few others: check whether those engines simply have no separate WAL directory before treating it as a gap.
  • duckpgq_graph OLTP at sf1 and sf10 ends with a DuckDB out-of-memory error (failed to allocate 8.0 GiB) labelled as a plain error (rc 1); it can be reclassified as an out-of-memory censor at report time.

Not covered by the audit: ArcadeDB rows. The pass so far runs the comparators only; ArcadeDB's four arms (embedded and server, JVM and native) come with the 26.11.1 pass. Their rows get the same audit at the four-arm smoke, before that pass starts.

Activity

  1. tae898 commented on Oct 30, 2026

    @tae898
    Author

    One more item for the next pass, found while fixing the dense lane (#556): in l1_tpc.py, l2_graph.py, e2_hybrid.py, l3_sparse.py and l4_tsbs.py the close_s timer starts before with _beat.phase("close"), so close_s includes the probe's idle settle (BENCH_MEMPROBE_IDLE_S, default 5 s) and its forced GC. close_s is harness bookkeeping (page_check.py lists it with settle_s, connect_s and the like, never as a page column), so no published number is affected. Fix for the next pass: start the timer inside the with, as #556 does for the dense lane.

  2. tae898 commented on Nov 6, 2026

    @tae898
    Author

    One more gap for the next pass, found while reading the mini's cgroup files for a resource-profile sidecar: runner.read_io_stat sums every device line of the container's io.stat, and on the mini that counts the written bytes twice.

    On the mini the file lists three devices. 259:0 (the NVMe) and 252:0 (the device-mapper device on top of it) show identical bytes, and 8:0 is a small separate device:

    8:0 rbytes=0 wbytes=0 rios=0 wios=5
    259:0 rbytes=0 wbytes=8691597312 rios=0 wios=82042
    252:0 rbytes=0 wbytes=8691597312 rios=0 wios=22387
    

    The sum is 16.2 GiB for 8.1 GiB actually written, so io_*_mib and io_*_mib_sum in the result rows are about 2x too high on the mini. A past row shows io_load_write_mib 16577.7 against 3899 MiB of data, which would put the write amplification at 4.3x instead of about 2.1x. export_web.py does not read these fields, and I found no table on the site or in the docs that uses them, so nothing published is affected as far as I can see.

    Fix for the next pass, together with the sampled-peak work in #559: store the per-device values and take the total from the whole-disk device (or the larger of a stacked pair), not the sum. I have not changed the harness, since the pass is running.

  3. tae898 commented on Nov 6, 2026

    @tae898
    Author

    Update 2026-11-06: I fixed this on the four-arm branch (bench/arcadedb-import-26111, PR #554), commit 6c9c58b5b8. main and the running paper pass are untouched, so I changed nothing mid-pass.

    read_io_stat and memory_probe.parse_io_stat (the memory probe's io_<phase>_*_mib fields had the same sum) now skip a device that is built on another device also listed in io.stat, read from /sys/dev/block/<maj:min>/slaves, with partitions resolved to their whole disk. The top of the stack is kept, so the mini's 259:0 plus 252:0 counts once, and an unrelated third device still adds up. A device that sysfs says nothing about is counted as before, which errs high rather than losing bytes. I did not take the larger of a pair because that undercounts a container that really writes to two disks. Return keys are unchanged and no row field was added, so page_check and the export see the same schema. The tests use the real mini io.stat lines and a synthetic sysfs tree.

    Rows written before the fix keep doubled io_* fields. For a row with host == "mini" the corrected value is the recorded one divided by 2, because the extra 8:0 term is 0 bytes. The laptop shows the same dm-over-NVMe layout in sysfs, but I have not read a container's io.stat there, so I make no claim about laptop rows yet. The rule and a small pure helper are in .notes/bench/repros/io-double-count-20261106, and no result file is modified.

    Plan: the fix lands on main together with #554 after the paper pass, and #559's per-device values can build on it.

  4. tae898 commented on Nov 6, 2026

    @tae898
    Author

    I opened two draft PRs for this, both against main and neither merged. #571 corrects the rows already written: at freeze time it halves the io_* figures of mini rows that lack the stamp io_stat_dedup == 1 in runs_paper.csv only, keeps the raw rows and values recoverable in a sidecar, declares the new column to page_check and provenance_check, and is not on the path the stage scripts or the runner import. It merges first. #570 is the harness fix (the commit from #554, cherry-picked): read_io_stat and parse_io_stat count a stacked block device once, and the runner stamps io_stat_dedup: 1 into every row it writes. It merges second, once #571 is in and the mini has finished the qC22 and qC23 re-runs, so the running pass splits cleanly into rows before and after the fix. No laptop rows feed the paper or the page, and I am not claiming a laptop factor.

    Edited in place: the first version of this comment described a manifest cutoff instead of the row stamp, and had the merge order unstated.

  5. tae898 commented on Nov 6, 2026

    @tae898
    Author

    Edit note: I replaced the comment above, because it described a manifest cutoff. #571 now reads a row stamp (io_stat_dedup == 1, written by the fixed runner in #570) and the two PRs merge in the order #571, then #570.

  6. self-assigned this
    on Nov 11, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions