Skip to content

DDIR inspect: format each record before writing to stderr - #910

Merged
frankmcsherry merged 1 commit into
master-nextfrom
ddir-inspect-format
Sep 28, 2026
Merged

frankmcsherry merged 1 commit into
master-nextfrom
ddir-inspect-format

Conversation

@frankmcsherry

Copy link
Copy Markdown
Member

inspect on both backends wrote each record with eprintln! while formatting it. For nested Debug values that is many small unbuffered writes to stderr, each taking stderr's global lock, and with several workers they queue behind one another. This formats each record into a String the operator reuses, then writes it with one eprint!. Output is unchanged: the same record syntax, still synchronous, and Rust test capture still works. The vec backend also stops cloning the value just to print it. Two files, +15/−2.

Measured on the stock DDIR tour, which inspects heavily (52,814 records). Three paired runs each, order reversed in the middle run, M4 release build. In every pair the inspected records are identical byte for byte (compared as sorted multisets), on both backends at 1 and 4 workers, and the final query outputs match the existing oracle.

Backend / workers Initial ms Ten churn ticks ms Process CPU s Peak footprint MiB
vec / 1 1700 → 87.86 358.91 → 19.42 2.05 → 0.11 35.13 → 41.02
vec / 4 1880 → 132.86 386.20 → 23.58 3.31 → 0.33 42.89 → 44.19
corgi / 1 1540 → 69.04 331.64 → 16.36 1.86 → 0.09 37.22 → 37.91
corgi / 4 1730 → 128.40 361.01 → 24.42 3.75 → 0.31 44.94 → 47.03

Memory cost. Peak footprint goes up. For vec at 1 worker the rise is consistent: 35.11–35.19 → 41.00–41.13 MiB. Corgi at 1 worker is about 0.7 MiB higher. Each operator's buffer keeps the capacity of its largest record, but this measurement does not show that the buffer accounts for the whole increase. The 4-worker peaks vary between runs.

Other workloads. SCC initial and churn times are within 0.7%. The AoC runner has the same median elapsed time (2.13 s at 1 worker, 2.24 s at 4 workers).

How this was found. Removing inspect from the tour takes its first tick from about 1.5 s to 5–15 ms. Most of the tour's measured time was stderr formatting, not dataflow work.

This makes inspect cheaper. It does not make it the right way to get data out: we'd like a columnar path for results, as a separate piece of work.

Tests. cargo test --release -p interactive: 104 passed, 5 ignored (all ignored before this change too). All 33 AoC answers match. The supported sessions match on both backends at 1 and 4 workers.

Measurements and the change are by Astra (OpenAI Codex). I re-ran the tests on master-next 9cfc909.

🤖 Generated with Claude Code

Reuse a record buffer per operator so nested Debug formatting does not issue many unbuffered writes under the global stderr lock. Preserve record formatting and synchronous output.

Co-Authored-By: Astra (OpenAI Codex)
Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
@frankmcsherry
frankmcsherry merged commit c8cd8e9 into master-next Sep 28, 2026
6 checks passed
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.

1 participant