Repository navigation
Conversation
`install.rs` had 8 raw `PROGRESS_BAR.inc(1)` plus a `set_length` that bypassed the `IS_TTY` short-circuit already present in `ProgressReceiver`. indicatif always takes the internal `Mutex<ProgressState>` write-lock even with a hidden draw target, so non-TTY runs (CI, piped output) were paying ~9k Mutex acquisitions per install. Wrapped them in `progress_inc` / `progress_set_length` helpers that match the receiver's gating pattern. This is 1/3 of the triplet from #2902, split out for independent A/B benchmarking against the recently-merged baseline #2887. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
The pcap-only bench was previously a one-off that captured `p1_resolve` across `utoo` and `bun`, and assumed the project tree was already cloned by `pm-bench-phases.sh` running in the same job. That gave us metadata fan-out, but install-phase regressions (#2902 / #2903 / #2904 / #2905 σ widening on `p0_full_cold`) live in the tarball download path, not in resolve. This commit makes the pcap bench self-contained and covers both phases for three PMs: - Self-clone the project if `$PROJECT_DIR` is missing (mirrors `pm-bench-phases.sh`), so this script runs as a standalone CI job. - Add a `<pm>-install` capture per PM: lock pre-existing, `cache + node_modules` wiped, then `<pm> install`. This is the cold-tarball-download phase where the σ-widening lives. - Add `utoo-next` as a third PM: built upstream by `build-linux`'s bench-baseline step (now also gated on `pm-bench-pcap`), downloaded via the same artifact path as `bench-phases-linux`. Skipped in local runs where `$UTOO_NEXT_BIN` is unset. Workflow change: - `pm-bench-pcap-linux` now downloads the `utoo-next-linux-x64` artifact and exports `UTOO_NEXT_BIN` exactly like `bench-phases-linux` does. - `Build next branch utoo` and `Upload utoo-next binary` steps in `build-linux` now also fire for `inputs.target == 'pm-bench-pcap'`, not only `pm-bench-phases`. Outputs in `/tmp/pm-bench-pcap`: dns.txt utoo-{resolve,install}.{pcap,log} utoo-next-{resolve,install}.{pcap,log} (when UTOO_NEXT_BIN set) bun-{resolve,install}.{pcap,log} Drives the analysis of whether the install hot-path's increased concurrency (FuturesUnordered streaming, zero-copy tar, TTY-gate) saturates outbound TCP and starves the download path. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Building on the install-phase pcap capture from the previous commit,
post-process each .pcap with tshark to extract pre-TLS metrics that
directly probe the "install greediness starves download" hypothesis
without needing TLS session-key dumping:
zero_windows — receive buffer full → server paused. Direct evidence
that the app's tokio runtime is not draining the
socket fast enough between extracts.
retransmits — server resent because ACK was late. Indirect
evidence of receive-side stall.
duplicate_acks — receiver re-sent ACK because it perceived a gap.
stream_gap_* — inter-packet gap distribution per TCP stream
(p50 / p99 / max in microseconds). p99 / max measure
the longest pause an active connection experienced —
if utoo shows multi-hundred-ms gaps where utoo-next
shows tens of ms, install is freezing the runtime
mid-download.
Per-capture summaries land at $PCAP_DIR/<name>.summary.json. They are
aggregated into a top-level summary.json via jq -s, so artifact
consumers can compare metrics across PMs without re-parsing the 100s
of MB of raw pcaps.
Single-pass tshark over the pcap with -T fields keeps cost bounded
to ~1 minute per 1 GB of capture; the full analysis pass runs after
all captures so it does not bleed into wall-clock measurement.
Workflow change:
Install pcap tools step now also installs tshark + jq, with
wireshark-common pre-seeded so tshark installs non-interactively
(we only read existing pcaps, no setuid dumpcap needed).
Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
The analysis pass aborted the whole job on the first .pcap because the wall-time grep returned no match, and `set -eo pipefail` propagated that exit-1 through `local x=$(grep | awk)` (the multi-line `local x; x=$(...)` form does NOT mask the exit code, unlike `local x=$(...)` on one line — bash gotcha). Two-part fix: 1. Drop into `set +e` / `set +o pipefail` for the analysis function body. The metrics are diagnostic — one tshark hiccup or an empty log line should not nuke a 25-minute capture run. Strict mode is restored at the end of the function so the rest of the script keeps its safety net. 2. Replace `grep -oE | awk` with awk-only. awk returns 0 even when no record matches, so empty-result log files no longer trip pipefail. Same parse, fewer pipes. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
…iagnosis
The TCP-level analysis (zero-copy retx=123 vs baseline 4-18) gave
strong evidence that utoo's receiver runtime is under back-pressure
during install, but it doesn't tell us *why*. The leading hypothesis
is disk IO saturation: rayon's parallel `fs::create + write_all` over
80k+ files in the ant-design tarball burst can outrun GitHub Actions
runners' Azure-disk IOPS budget, blocking write threads → tokio
threads back up → socket buffers fill.
This commit adds an iostat-x sampler to each capture:
capture_one() now spawns `iostat -x -y 1` in parallel with
tcpdump, writing per-second device samples to
$PCAP_DIR/<name>.iostat.txt. Both samplers are torn down with
the workload command.
analyze_pcap() parses the iostat log via column-position lookup
(sysstat header row → column index map) and extracts:
io_util_max_pct — peak disk-busy percentage
io_util_avg_pct — average disk-busy percentage
io_w_iops_max — peak write IOPS
io_w_kbs_max — peak write throughput (kB/s)
io_w_await_max_ms — peak write queue wait (ms)
io_samples — sample count for sanity check
These six fields land in summary.json alongside the TCP metrics, so
artifact consumers can directly cross-correlate disk pressure with
TCP back-pressure within the same capture window.
The decision rule:
* If io_util_max_pct stays high (>80%) on the experiment branch
while baseline same-PM utoo-next stays low → install path is
saturating disk and that's the mechanism.
* If both branches show similar low %util, disk is not the
bottleneck and we keep looking (e.g. CPU contention).
Workflow: apt install adds `sysstat` (iostat lives there). It is
preinstalled on ubuntu-latest images today, but pinning the
dependency makes future image rebuilds resilient.
Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
A/B observation experiment for the +1.75s p3 regression on TTY-gate (#2903) that survived the par_chunks(64) disk-burst fix. Pcap+iostat on the new architecture showed: utoo zwin = 16 (baseline 2) ← receiver back-pressure utoo retx = 16 (baseline 10) utoo gap_p99 = 1.98ms ← TCP path itself fast util_max = 75% (baseline 76%) ← disk identical w_await = 27ms (baseline 85) ← disk identical So the regression mechanism is *not* disk and *not* network latency — it's tokio runtime starvation: the install_packages spawn loop runs synchronously through ~2000+ packages per layer, with no await points except inside the spawned tasks themselves. Before TTY-gate each iteration called PROGRESS_BAR.inc(1), whose indicatif internal mutex + state mutation gave the runtime a per-package microsecond pause; in single-threaded contexts that's enough for the runtime to service ready socket reads on in-flight tarball downloads. With TTY-gate's IS_TTY short-circuit on CI, that microsecond goes away, the spawn loop runs uninterrupted, and the kernel's recv buffer fills before tokio gets back to drain it — hence zwin events. Hypothesis: a deliberate `tokio::task::yield_now().await` every 32 iterations restores the implicit yield without the mutex cost. If the hypothesis is right we expect on the new bench: - p3 Δ vs utoo-next collapses from +1.75s back toward ≈0 - pcap zwin drops from 16 toward baseline (≤5) - p0/p1/p4 unaffected - retx unchanged (was already in baseline range) If wrong: - zwin stays high → the mechanism is elsewhere (maybe the spawn pace itself, not yield availability — would need throttling rather than yielding) - p3 still high → consider closing #2903 instead YIELD_EVERY=32 picked to keep yield overhead negligible on cheap omit/skip iterations while still firing ~60-80 times per typical ant-design layer. If the regression collapses but p3 over-corrects toward a worse value than baseline, try EVERY=64 or per-iteration based on which direction it moved. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
There was a problem hiding this comment.
Code Review
This pull request optimizes the package installation process by introducing TTY-gated progress bar updates to reduce mutex contention in non-TTY environments and adding cooperative yielding in the installation loop to improve concurrency. Feedback includes a fix for a potential compilation error regarding the use of is_multiple_of on primitive types, suggestions to move the yield counter for better consistency across dependency layers, gating log allocations for further performance gains in CI, and correcting documentation to match function signatures.
| if let Some(packages) = groups.get(depth) { | ||
| for (path, package) in packages.iter() { | ||
| iter_count += 1; | ||
| if iter_count.is_multiple_of(YIELD_EVERY) { |
There was a problem hiding this comment.
The is_multiple_of method is not available on primitive integer types like usize in the standard library (it was only stabilized for NonZero types in Rust 1.79). Unless a custom trait is being imported that provides this method, this will cause a compilation error. Using the remainder operator % is the standard and more portable way to perform this check.
| if iter_count.is_multiple_of(YIELD_EVERY) { | |
| if iter_count % YIELD_EVERY == 0 { |
|
|
||
| for depth in depths.iter() { | ||
| let mut clone_tasks: Vec<tokio::task::JoinHandle<Result<()>>> = Vec::new(); | ||
| let mut iter_count: usize = 0; |
There was a problem hiding this comment.
The iter_count is currently reset for every depth level. In projects with many small dependency layers (e.g., a deep but narrow tree), this might prevent the cooperative yield from ever triggering, even if the total number of packages is large. Moving this counter outside the depths loop ensures a consistent yield cadence across the entire installation process, regardless of how packages are distributed across levels.
| return Err(e); | ||
| } | ||
| PROGRESS_BAR.inc(1); | ||
| progress_inc(1); |
There was a problem hiding this comment.
While progress_inc is now gated by IS_TTY, the log_progress call on the following line still executes a format! macro, which performs a string allocation even in non-TTY environments (like CI). To fully achieve the 'zero-cost' goal for CI mentioned in the PR description and the IS_TTY documentation, consider gating this call as well by checking IS_TTY before the allocation occurs.
| PROGRESS_BAR.set_message(text.to_string()); | ||
| } | ||
|
|
||
| /// TTY-gated `PROGRESS_BAR.inc(1)`. Non-TTY callers pay no Mutex cost — |
There was a problem hiding this comment.
The doc comment mentions inc(1), but the function signature accepts a generic n: u64. It is better to keep the documentation consistent with the implementation.
| /// TTY-gated `PROGRESS_BAR.inc(1)`. Non-TTY callers pay no Mutex cost — | |
| /// TTY-gated PROGRESS_BAR.inc(n). Non-TTY callers pay no Mutex cost — |
📊 pm-bench-phases ·
|
| PM | wall | ±σ | user | sys | RSS | pgMinor |
|---|---|---|---|---|---|---|
| bun | 8.97s | 0.21s | 10.11s | 10.12s | 707M | 322.8K |
| utoo-next | 8.37s | 0.15s | 10.85s | 12.34s | 941M | 119.6K |
| utoo-npm | 8.28s | 0.21s | 11.02s | 12.45s | 1.38G | 182.5K |
| utoo | 0.00s | 0.00s | 9.69s | 8.73s | 967M | 121.4K |
| PM | vCtx | iCtx | netRX | netTX | cache | node_mod | lock |
|---|---|---|---|---|---|---|---|
| bun | 15.3K | 17.1K | 1.16G | 6M | 1.81G | 1.70G | 1M |
| utoo-next | 119.1K | 85.6K | 1.14G | 5M | 1.68G | 1.68G | 2M |
| utoo-npm | 124.3K | 88.9K | 1.14G | 5M | 1.68G | 1.68G | 2M |
| utoo | 116.9K | 48.6K | 1.14G | 5M | 1.68G | - | - |
p1_resolve
| PM | wall | ±σ | user | sys | RSS | pgMinor |
|---|---|---|---|---|---|---|
| bun | 1.96s | 0.05s | 3.97s | 1.01s | 507M | 157.6K |
| utoo-next | 3.07s | 0.04s | 5.43s | 1.93s | 607M | 83.7K |
| utoo-npm | 3.04s | 0.01s | 5.38s | 1.95s | 608M | 80.5K |
| utoo | 3.15s | 0.10s | 5.47s | 1.99s | 595M | 80.1K |
| PM | vCtx | iCtx | netRX | netTX | cache | node_mod | lock |
|---|---|---|---|---|---|---|---|
| bun | 8.7K | 4.3K | 202M | 3M | 105M | - | 1M |
| utoo-next | 68.7K | 113.8K | 199M | 2M | 7M | 3M | 2M |
| utoo-npm | 68.1K | 113.0K | 199M | 2M | 7M | 3M | 2M |
| utoo | 71.3K | 112.6K | 199M | 2M | 7M | 3M | 2M |
p3_cold_install
| PM | wall | ±σ | user | sys | RSS | pgMinor |
|---|---|---|---|---|---|---|
| bun | 6.74s | 0.15s | 6.12s | 9.91s | 621M | 205.3K |
| utoo-next | 6.94s | 1.96s | 4.98s | 10.94s | 479M | 65.7K |
| utoo-npm | 6.93s | 0.38s | 5.33s | 11.17s | 909M | 121.6K |
| utoo | 5.68s | 0.11s | 4.89s | 10.43s | 461M | 59.3K |
| PM | vCtx | iCtx | netRX | netTX | cache | node_mod | lock |
|---|---|---|---|---|---|---|---|
| bun | 3.7K | 6.8K | 995M | 4M | 1.74G | 1.74G | 1M |
| utoo-next | 110.5K | 51.8K | 964M | 3M | 1.67G | 1.67G | 2M |
| utoo-npm | 104.4K | 62.0K | 964M | 2M | 1.67G | 1.67G | 2M |
| utoo | 85.7K | 46.2K | 964M | 2M | 1.67G | 1.67G | 2M |
p4_warm_link
| PM | wall | ±σ | user | sys | RSS | pgMinor |
|---|---|---|---|---|---|---|
| bun | 3.30s | 0.09s | 0.21s | 2.32s | 136M | 31.6K |
| utoo-next | 2.42s | 0.50s | 0.55s | 3.80s | 79M | 18.3K |
| utoo-npm | 2.13s | 0.08s | 0.55s | 3.80s | 85M | 19.3K |
| utoo | 2.34s | 0.06s | 0.54s | 3.81s | 78M | 18.1K |
| PM | vCtx | iCtx | netRX | netTX | cache | node_mod | lock |
|---|---|---|---|---|---|---|---|
| bun | 249 | 22 | 5M | 14K | 1.88G | 1.72G | 1M |
| utoo-next | 42.4K | 19.2K | 307K | 11K | 1.68G | 1.68G | 2M |
| utoo-npm | 46.3K | 21.1K | 319K | 9K | 1.68G | 1.68G | 2M |
| utoo | 40.6K | 17.7K | 307K | 12K | 1.68G | 1.68G | 2M |
npmmirror.com: no output captured.
Pcap on the partition design without this (run 25551591284) measured
utoo install zwin=14 vs utoo-next 0 — the partition removed the
cheap-path synchronous burst (Phase 1+2 finish before any download
spawns) but Phase 3 still left residual receiver-side back-pressure.
Mechanism: `tokio::spawn(execute_clone(work)).await?` inside the
stream poll loop does not give the runtime a guaranteed yield window
between consecutive items when the JoinHandle resolves immediately
(cache hit, fast small tarball). The stream task moves straight to
the next spawn, polls it, etc. — a tight inner loop where the
runtime never gets to service in-flight socket reads on tarball
downloads on the OTHER 63 in-flight clones whose downloads are
ongoing.
Adding one explicit `yield_now().await` per item in the stream poll
loop costs ~100ns per iteration (one Waker schedule), at most a few
ms total per layer. In return the kernel recv buffer drains before
filling, so server-side zwin events disappear.
Decision rule on rerun:
zwin ≤ 5 with this commit → mechanism fully fixed; ship.
zwin still > 8 → look elsewhere (download semaphore
interaction with stream poll order?).
Note: this is the same `yield_now` pattern proposed in the
short-lived #2910 experiment, but applied at the right architectural
layer (Phase 3 only — Phase 1+2 do not need it). Phase 3 is the only
place a synchronous burst can starve sockets, and one yield per
stream-poll item is the structurally minimal hint.
Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Why
Companion experiment to #2903 (TTY-gate). After #2905 (zero-copy + par_chunks) merged, TTY-gate's phases bench still showed a stable +1.75s p3 regression on N=3, but pcap+iostat on the new arch (run 25535139270) ruled out disk and TCP path:
tcp.analysis.zero_windowevents: utoo 16 vs utoo-next 2 — receiver back-pressureretransmits: 16 vs 10 (baseline range)gap_p99: 1.98ms vs 2.5ms (TCP itself fast)util_max/w_await: identical disk profileSo the regression is tokio runtime starvation, not disk burst.
Hypothesis
Before #2903, every iteration of the synchronous spawn loop in
install_packagescalledPROGRESS_BAR.inc(1). indicatif's internal mutex+state update gave the runtime a per-package microsecond pause — enough on a single-threaded executor to interleave socket reads on in-flight tarball downloads. Removing the call eliminated the implicit yield; the spawn loop now runs uninterrupted through ~2000 packages per layer, the kernel recv buffer fills before tokio drains it, server emits zero-window pauses.Change
Restores the implicit yield without re-introducing the indicatif mutex cost.
Decision matrix
No merge intent — pure observation experiment. If signal looks good, fold the change into #2903 and graduate together.
🤖 Generated with Claude Code