From 9edee782aa1759815715505b41c680ec270504dd Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Wed, 3 Jun 2026 15:46:54 -0400 Subject: [PATCH 01/18] feat: add futures dependency for ready-signal select logic --- Cargo.lock | 122 +++++++++++++++++++++++++++++++++++++++++++++-------- Cargo.toml | 1 + 2 files changed, 105 insertions(+), 18 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index e1f4736..7ca907d 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -38,7 +38,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a3203e79f4dd9bdda415ed03cf14dae5a2bf775c683a00f94e9cd1faf0f596e5" dependencies = [ "quote", - "syn", + "syn 1.0.60", ] [[package]] @@ -316,7 +316,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "e8f45d9ad417bcef4817d614a501ab55cdd96a6fdb24f49aab89a54acfd66b19" dependencies = [ "quote", - "syn", + "syn 1.0.60", ] [[package]] @@ -379,26 +379,53 @@ version = "0.1.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a06f77d526c1a601b7c4cdd98f54b5eaabffc14d5f2f0296febdc7f357c6d3ba" +[[package]] +name = "futures" +version = "0.3.31" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "65bc07b1a8bc7c85c5f2e110c476c7389b4554ba72af57d8445ea63a576b0876" +dependencies = [ + "futures-channel", + "futures-core", + "futures-executor", + "futures-io", + "futures-sink", + "futures-task", + "futures-util", +] + [[package]] name = "futures-channel" -version = "0.3.13" +version = "0.3.32" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8c2dd2df839b57db9ab69c2c9d8f3e8c81984781937fe2807dc6dcf3b2ad2939" +checksum = "07bbe89c50d7a535e539b8c17bc0b49bdb77747034daa8087407d655f3f7cc1d" dependencies = [ "futures-core", + "futures-sink", ] [[package]] name = "futures-core" -version = "0.3.13" +version = "0.3.32" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7e3450815272ef58cec6d564423f6e755e25379b217b0bc688e295ba24df6b1d" + +[[package]] +name = "futures-executor" +version = "0.3.31" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "15496a72fabf0e62bdc3df11a59a3787429221dd0710ba8ef163d6f7a9112c94" +checksum = "1e28d1d997f585e54aebc3f97d39e72338912123a67330d723fdbb564d646c9f" +dependencies = [ + "futures-core", + "futures-task", + "futures-util", +] [[package]] name = "futures-io" -version = "0.3.13" +version = "0.3.32" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d71c2c65c57704c32f5241c1223167c2c3294fd34ac020c807ddbe6db287ba59" +checksum = "cecba35d7ad927e23624b22ad55235f2239cfa44fd10428eecbeba6d6a717718" [[package]] name = "futures-lite" @@ -415,6 +442,47 @@ dependencies = [ "waker-fn", ] +[[package]] +name = "futures-macro" +version = "0.3.31" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "162ee34ebcb7c64a8abebc059ce0fee27c2262618d7b60ed8faf72fef13c3650" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.117", +] + +[[package]] +name = "futures-sink" +version = "0.3.32" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c39754e157331b013978ec91992bde1ac089843443c49cbc7f46150b0fad0893" + +[[package]] +name = "futures-task" +version = "0.3.32" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "037711b3d59c33004d3856fbdc83b99d4ff37a24768fa1be9ce3538a1cde4393" + +[[package]] +name = "futures-util" +version = "0.3.31" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9fa08315bb612088cc391249efdc3bc77536f16c91f6cf495e6fbe85b20a4a81" +dependencies = [ + "futures-channel", + "futures-core", + "futures-io", + "futures-macro", + "futures-sink", + "futures-task", + "memchr", + "pin-project-lite", + "pin-utils", + "slab", +] + [[package]] name = "getrandom" version = "0.2.8" @@ -780,18 +848,18 @@ dependencies = [ [[package]] name = "proc-macro2" -version = "1.0.24" +version = "1.0.106" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1e0704ee1a7e00d7bb417d0770ea303c1bccbabf0ef1667dae92b5967f5f8a71" +checksum = "8fd00f0bb2e90d81d1044c2b32617f68fcb9fa3bb7640c23e9c748e53fb30934" dependencies = [ - "unicode-xid", + "unicode-ident", ] [[package]] name = "quote" -version = "1.0.9" +version = "1.0.45" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c3d0b9745dc2debf507c8422de05d7226cc1f0644216dfdfead988f9b1ab32a7" +checksum = "41f2619966050689382d2b44f664f4bc593e129785a36d6ee376ddf37259b924" dependencies = [ "proc-macro2", ] @@ -946,7 +1014,7 @@ checksum = "1800f7693e94e186f5e25a28291ae1570da908aff7d97a095dec1e56ff99069b" dependencies = [ "proc-macro2", "quote", - "syn", + "syn 1.0.60", ] [[package]] @@ -992,7 +1060,7 @@ checksum = "b2acd6defeddb41eb60bb468f8825d0cfd0c2a76bc03bfd235b6a1dc4f6a1ad5" dependencies = [ "proc-macro2", "quote", - "syn", + "syn 1.0.60", ] [[package]] @@ -1034,6 +1102,7 @@ dependencies = [ "assert_cmd", "async-std", "caps", + "futures", "indexmap 2.9.0", "lazy_static", "nix", @@ -1081,6 +1150,17 @@ dependencies = [ "unicode-xid", ] +[[package]] +name = "syn" +version = "2.0.117" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e665b8803e7b1d2a727f4023456bbbbe74da67099c585258af0ad9c5013b9b99" +dependencies = [ + "proc-macro2", + "quote", + "unicode-ident", +] + [[package]] name = "tempdir" version = "0.3.7" @@ -1108,7 +1188,7 @@ checksum = "982d17546b47146b28f7c22e3d08465f6b8903d0ea13c1660d9d84a6e7adcdbb" dependencies = [ "proc-macro2", "quote", - "syn", + "syn 1.0.60", ] [[package]] @@ -1126,6 +1206,12 @@ version = "0.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a7f741b240f1a48843f9b8e0444fb55fb2a4ff67293b50a9179dfd5ea67f8d41" +[[package]] +name = "unicode-ident" +version = "1.0.24" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e6e4313cd5fcd3dad5cafa179702e2b244f760991f45397d14d4ebf38247da75" + [[package]] name = "unicode-xid" version = "0.2.1" @@ -1195,7 +1281,7 @@ dependencies = [ "log", "proc-macro2", "quote", - "syn", + "syn 1.0.60", "wasm-bindgen-shared", ] @@ -1229,7 +1315,7 @@ checksum = "cc053ec74d454df287b9374ee8abb36ffd5acb95ba87da3ba5b7d3fe20eb401e" dependencies = [ "proc-macro2", "quote", - "syn", + "syn 1.0.60", "wasm-bindgen-backend", "wasm-bindgen-shared", ] diff --git a/Cargo.toml b/Cargo.toml index 695cd91..3bd8f0a 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -22,6 +22,7 @@ serde = { version = "1.0.124", features = ["derive"] } anyhow = "<=1.0.48" which = "4.0.2" indexmap = { version = "2.9.0", features = ["serde"] } +futures = "0.3" [target.'cfg(target_os = "linux")'.dependencies] perfcnt = "0.8.0" From d9f3e214b8df5324b4f7462bb7233d387bbfe398 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Wed, 3 Jun 2026 15:48:53 -0400 Subject: [PATCH 02/18] refactor: add ready_fd parameter to run_cmd (all callers pass None) --- src/main.rs | 5 +++-- src/subproc.rs | 11 ++++++++--- 2 files changed, 11 insertions(+), 5 deletions(-) diff --git a/src/main.rs b/src/main.rs index 6ddaa91..0aab6ca 100644 --- a/src/main.rs +++ b/src/main.rs @@ -80,7 +80,7 @@ async fn run_test(config: &Config, mut metrics: &mut HashMap Result> { Ok(match &config.service { - Some(command_arr) => Some(run_cmd(command_arr, &config.env)?), + Some(command_arr) => Some(run_cmd(command_arr, &config.env, None)?), None => None, }) } @@ -128,6 +128,7 @@ async fn run_iteration( let mut child = run_cmd( &env::args().take(1).collect::>(), &sub_config.env, + None, )?; let status = child.status().await?; let status = status.code().expect("no exit code"); diff --git a/src/subproc.rs b/src/subproc.rs index c841dc6..466c57b 100644 --- a/src/subproc.rs +++ b/src/subproc.rs @@ -3,7 +3,7 @@ use async_std::{ process::{Command, Child, Stdio}, task::sleep, }; -use std::{collections::HashMap, env, os::unix::process::ExitStatusExt, time::Duration}; +use std::{collections::HashMap, env, os::unix::{io::RawFd, process::ExitStatusExt}, time::Duration}; use crate::config::*; @@ -27,7 +27,7 @@ async fn run_setup_or_teardown(typ: &str, config: &Config) -> Result<()> { if attempts == 100 { bail!("{} script did not complete successfully. aborting.", typ); } - let mut child = run_cmd(command_arr, env)?; + let mut child = run_cmd(command_arr, env, None)?; let status = child.status().await?; let maybe_code = status.code(); if let Some(maybe_code) = maybe_code { @@ -67,12 +67,17 @@ fn get_stdio() -> Stdio { pub(crate) fn run_cmd( command_arr: &[String], env: &HashMap, + ready_fd: Option, ) -> Result { + let mut env = env.clone(); + if let Some(fd) = ready_fd { + env.insert("SIRUN_READY_FD".into(), fd.to_string()); + } let command = command_arr[0].clone(); let args = command_arr.iter().skip(1); Command::new(command) .args(args) - .envs(env.clone()) + .envs(env) .stdout(get_stdio()) .stderr(get_stdio()) .spawn() From 973404a7d01db56d37a5c2cec9ddd5f860422ca8 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Wed, 3 Jun 2026 15:50:24 -0400 Subject: [PATCH 03/18] test: add failing integration tests for SIRUN_READY_FD ready signal --- examples/ready-signal.json | 3 +++ tests/examples.rs | 40 ++++++++++++++++++++++++++++++++++++++ 2 files changed, 43 insertions(+) create mode 100644 examples/ready-signal.json diff --git a/examples/ready-signal.json b/examples/ready-signal.json new file mode 100644 index 0000000..5b94efd --- /dev/null +++ b/examples/ready-signal.json @@ -0,0 +1,3 @@ +{ + "run": "bash -c 'sleep 0.5; echo x >&$SIRUN_READY_FD'" +} diff --git a/tests/examples.rs b/tests/examples.rs index 1b0cf41..6cdbf23 100644 --- a/tests/examples.rs +++ b/tests/examples.rs @@ -297,3 +297,43 @@ fn insctrution_counts() { fn service() { run!("./examples/service.json").assert().success(); } + +#[test] +#[serial] +fn ready_signal_resets_wall_time() { + json_has!( + "./examples/ready-signal.json", + |map: &serde_yaml::Mapping| { + let wall_time = map + .get(&"iterations".into()) + .unwrap() + .as_sequence() + .unwrap()[0] + .as_mapping() + .unwrap() + .get(&"wall.time".into()) + .unwrap() + .as_f64() + .unwrap(); + // Startup is 500ms; post-ready work is ~0ms. + // With ready signal: wall.time << 500_000μs. + // Threshold of 200_000μs gives generous headroom. + wall_time < 200_000.0 + } + ); +} + +#[test] +#[serial] +fn ready_signal_fallback_when_no_signal() { + // App exits without writing to SIRUN_READY_FD — full timing used. + json_has!("./examples/simple.json", |map: &serde_yaml::Mapping| { + // simple.json has no ready signal; we just verify it still runs normally. + map.get(&"iterations".into()) + .unwrap() + .as_sequence() + .unwrap() + .len() + == 1 + }); +} From cd7a79a11e205a8d0b8e9638575ddcf867134646 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Wed, 3 Jun 2026 15:58:15 -0400 Subject: [PATCH 04/18] feat: implement SIRUN_READY_FD ready-signal for startup exclusion --- src/main.rs | 146 ++++++++++++++++++++++++++++++++++++++++++++-------- 1 file changed, 125 insertions(+), 21 deletions(-) diff --git a/src/main.rs b/src/main.rs index 0aab6ca..67a9f62 100644 --- a/src/main.rs +++ b/src/main.rs @@ -11,7 +11,12 @@ use async_std::{ task::{sleep, spawn}, }; use serde_json::json; -use std::{collections::HashMap, env, os::unix::process::ExitStatusExt, process::exit}; +use std::{ + collections::HashMap, + env, + os::unix::{io::{FromRawFd, RawFd}, process::ExitStatusExt}, + process::exit, +}; use which::which; use indexmap::IndexMap; @@ -48,29 +53,110 @@ async fn test_timeout(timeout: u64) { exit(1); } +async fn read_one_byte(fd: RawFd) -> bool { + async_std::task::spawn_blocking(move || { + let mut buf = [0u8; 1]; + let mut f = unsafe { std::fs::File::from_raw_fd(fd) }; + matches!(std::io::Read::read(&mut f, &mut buf), Ok(n) if n > 0) + }) + .await +} + +async fn wait_with_ready_signal( + child: &mut Child, + read_fd: RawFd, + start_time: &mut std::time::Instant, + rusage_start: &mut Rusage, +) -> Result { + let pipe_fut = read_one_byte(read_fd); + let status_fut = child.status(); + futures::pin_mut!(pipe_fut, status_fut); + match futures::future::select(pipe_fut, status_fut).await { + futures::future::Either::Left((got_signal, remaining)) => { + if got_signal { + *start_time = std::time::Instant::now(); + *rusage_start = Rusage::new(); + } + // No signal (EOF without data): child exited without writing to + // SIRUN_READY_FD. Use original timers — full process lifetime + // is measured. + remaining.await.map_err(Into::into) + } + // Child exited before any data was written to the pipe. + // Use original timers — full process lifetime is measured. + futures::future::Either::Right((status, _)) => status.map_err(Into::into), + } +} + #[cfg(target_os = "linux")] -async fn run_with_instruction_count(child: &mut Child, config: &Config) -> Result<(ExitStatus, Option)> { +async fn run_with_instruction_count( + child: &mut Child, + config: &Config, + read_fd: RawFd, + start_time: &mut std::time::Instant, + rusage_start: &mut Rusage, +) -> Result<(ExitStatus, Option)> { use perfcnt::AbstractPerfCounter; - use perfcnt::linux::{PerfCounterBuilderLinux, HardwareEventType}; - if config.instructions { - let pid = child.id(); - let mut counter = PerfCounterBuilderLinux::from_hardware_event(HardwareEventType::Instructions) - .for_pid(pid as i32) - .finish()?; - counter.start()?; - let status = child.status().await?; - counter.stop()?; - let instructions = counter.read()?; + use perfcnt::linux::{HardwareEventType, PerfCounterBuilderLinux}; - Ok((status, Some(instructions))) - } else { - Ok((child.status().await?, None)) + if !config.instructions { + return Ok(( + wait_with_ready_signal(child, read_fd, start_time, rusage_start).await?, + None, + )); } + + let pid = child.id(); + let mut counter = + PerfCounterBuilderLinux::from_hardware_event(HardwareEventType::Instructions) + .for_pid(pid as i32) + .finish()?; + counter.start()?; + + let pipe_fut = read_one_byte(read_fd); + let status_fut = child.status(); + futures::pin_mut!(pipe_fut, status_fut); + + let (startup_instructions, status) = + match futures::future::select(pipe_fut, status_fut).await { + futures::future::Either::Left((got_signal, remaining)) => { + let startup = if got_signal { + *start_time = std::time::Instant::now(); + *rusage_start = Rusage::new(); + counter.stop()?; + let val = counter.read()?; + counter.start()?; + val + } else { + // Child closed write end (exited) without writing to + // SIRUN_READY_FD. Use original timers and count all + // instructions from process start. + 0 + }; + (startup, remaining.await?) + } + // Child exited before any data arrived on the pipe. + // Use original timers and count all instructions from process start. + futures::future::Either::Right((status, _)) => (0, status?), + }; + + counter.stop()?; + let total = counter.read()?; + Ok((status, Some(total - startup_instructions))) } #[cfg(not(target_os = "linux"))] -async fn run_with_instruction_count(child: &mut Child, _config: &Config) -> Result<(ExitStatus, Option)> { - Ok((child.status().await?, None)) +async fn run_with_instruction_count( + child: &mut Child, + _config: &Config, + read_fd: RawFd, + start_time: &mut std::time::Instant, + rusage_start: &mut Rusage, +) -> Result<(ExitStatus, Option)> { + Ok(( + wait_with_ready_signal(child, read_fd, start_time, rusage_start).await?, + None, + )) } async fn run_test(config: &Config, mut metrics: &mut HashMap) -> Result<()> { @@ -78,10 +164,28 @@ async fn run_test(config: &Config, mut metrics: &mut HashMap Date: Wed, 3 Jun 2026 15:59:05 -0400 Subject: [PATCH 05/18] docs: document SIRUN_READY_FD environment variable --- README.md | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/README.md b/README.md index 7834e43..384fcb3 100644 --- a/README.md +++ b/README.md @@ -99,6 +99,15 @@ Create a JSON or YAML file with the following properties: communication between tested processes and sirun. By default a random port will be assigned. You should read this variable from tested programs to determine which port to send data to. +* **`SIRUN_READY_FD`**: A writable file descriptor provided by sirun to the + benchmarked process. Write any byte to this descriptor to signal that startup + is complete; sirun will reset `wall.time`, `user.time`, `system.time`, + `cpu.pct.wall.time`, and (Linux only) `instructions` to measure only the + post-ready period. If the process exits without writing to this descriptor, + sirun falls back to measuring the full process lifetime. Example (Node.js): + ```js + require('fs').writeSync(parseInt(process.env.SIRUN_READY_FD), 'x'); + ``` ### Example From 2cd47b5b186d7f7d86a230e6a1dfdbadc48ce6b1 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Wed, 3 Jun 2026 16:09:09 -0400 Subject: [PATCH 06/18] fix: user/system time cover full lifetime; remove dead rusage reset RUSAGE_CHILDREN only updates after a child exits and is waited for, so the rusage snapshot taken at signal time is identical to the original baseline. Only wall.time and instructions (Linux) are post-ready; document this accurately in README and spec. --- README.md | 10 +- .../specs/2026-06-03-ready-signal-design.md | 99 +++++++++++++++++++ src/main.rs | 15 ++- 3 files changed, 111 insertions(+), 13 deletions(-) create mode 100644 docs/superpowers/specs/2026-06-03-ready-signal-design.md diff --git a/README.md b/README.md index 384fcb3..2ad8a8f 100644 --- a/README.md +++ b/README.md @@ -101,10 +101,12 @@ Create a JSON or YAML file with the following properties: determine which port to send data to. * **`SIRUN_READY_FD`**: A writable file descriptor provided by sirun to the benchmarked process. Write any byte to this descriptor to signal that startup - is complete; sirun will reset `wall.time`, `user.time`, `system.time`, - `cpu.pct.wall.time`, and (Linux only) `instructions` to measure only the - post-ready period. If the process exits without writing to this descriptor, - sirun falls back to measuring the full process lifetime. Example (Node.js): + is complete; sirun will reset `wall.time` (and `instructions` on Linux) to + measure only the post-ready period. `user.time`, `system.time`, + `cpu.pct.wall.time`, and `max.res.size` always cover the full process + lifetime regardless of the signal. If the process exits without writing to + this descriptor, sirun falls back to measuring the full process lifetime. + Example (Node.js): ```js require('fs').writeSync(parseInt(process.env.SIRUN_READY_FD), 'x'); ``` diff --git a/docs/superpowers/specs/2026-06-03-ready-signal-design.md b/docs/superpowers/specs/2026-06-03-ready-signal-design.md new file mode 100644 index 0000000..9b0058c --- /dev/null +++ b/docs/superpowers/specs/2026-06-03-ready-signal-design.md @@ -0,0 +1,99 @@ +# Ready Signal Design + +**Date:** 2026-06-03 +**Status:** Approved + +## Problem + +Sirun starts measuring from the moment the benchmarked process is launched. For +interpreted-language apps (Node.js, Python, etc.), module loading and other +startup work can account for a significant portion of the measured time, +obscuring the actual benchmark signal. + +## Goal + +Allow the benchmarked app to signal when it is ready to be measured, so that +startup time is excluded from all reported metrics. + +## Design + +### Signal mechanism + +Before spawning the benchmarked command, the inner sirun process (the one that +runs per-iteration, detected by `SIRUN_ITERATION`) creates a Unix pipe. The +write-end fd number is passed to the child via the `SIRUN_READY_FD` environment +variable. The write-end is explicitly inherited by the child using +`CommandExt::fd`; all other extra fds remain close-on-exec. + +After spawning the child, the inner sirun closes its copy of the write-end and +runs an async `select!` racing two futures: + +1. **Read from the pipe read-end** — data arrives, meaning the app signaled ready. +2. **Child exits** — the process ended before signaling. + +### On signal received (case 1) + +- `start_time` (`std::time::Instant`) is reset to now. +- On Linux with `instructions: true`: the counter is stopped, its value saved + as `startup_instructions`, then restarted. The final post-ready instruction + count is `total_instructions - startup_instructions`. (Stop/restart is used + rather than reading while running, since `perfcnt` requires the counter to + be stopped before reading.) +- Only the first write to `SIRUN_READY_FD` has any effect. After the first + read, Sirun stops watching the pipe and proceeds to wait for the child to exit. + +### On child exit before signal (case 2) + +Silent fallback: Sirun uses the original `start_time` and `rusage` baseline. +No warning is emitted. The app simply did not use the feature. + +### Usage + +```js +// Node.js — after all imports and startup work +require('fs').writeSync(parseInt(process.env.SIRUN_READY_FD), 'x'); +``` + +```python +# Python — after all imports and startup work +import os +os.write(int(os.environ['SIRUN_READY_FD']), b'x') +``` + +```sh +# Shell — after startup work +echo x >&$SIRUN_READY_FD +``` + +## Metrics + +| Metric | When signal received | When no signal | +|---------------------|-------------------------------|---------------------| +| `wall.time` | Post-ready period only | Full lifetime | +| `user.time` | Full lifetime (RUSAGE_CHILDREN limitation) | Full lifetime | +| `system.time` | Full lifetime (RUSAGE_CHILDREN limitation) | Full lifetime | +| `cpu.pct.wall.time` | Full lifetime (derived from user+system) | Full lifetime | +| `instructions` | Post-ready only (Linux) | Full lifetime | +| `max.res.size` | Full lifetime (not reset) | Full lifetime | + +`max.res.size`, `user.time`, `system.time`, and `cpu.pct.wall.time` always +reflect the full process lifetime. `RUSAGE_CHILDREN` (used for the rusage +metrics) only updates after a child exits and is waited for, so it cannot be +sampled mid-run in a meaningful way. + +## Config changes + +No new config fields. The pipe is always created and `SIRUN_READY_FD` is always +set in the child's environment. Apps opt in by writing to the fd. + +## Implementation notes + +- Pipe creation and the `select!` live in `run_test()` in `src/main.rs`. +- `run_cmd()` in `src/subproc.rs` needs a new optional parameter (or a + separate variant) to accept an fd to explicitly inherit via + `std::os::unix::process::CommandExt::fd`. +- The Linux instruction counter path in `run_with_instruction_count()` needs + to accept a signal channel; on signal it stops the counter, saves the value, + and restarts it. The final reported value is `total - startup_instructions`. +- `SIRUN_READY_FD` should be documented in the README alongside the other + environment variables. diff --git a/src/main.rs b/src/main.rs index 67a9f62..6b5c6b2 100644 --- a/src/main.rs +++ b/src/main.rs @@ -66,7 +66,6 @@ async fn wait_with_ready_signal( child: &mut Child, read_fd: RawFd, start_time: &mut std::time::Instant, - rusage_start: &mut Rusage, ) -> Result { let pipe_fut = read_one_byte(read_fd); let status_fut = child.status(); @@ -75,7 +74,6 @@ async fn wait_with_ready_signal( futures::future::Either::Left((got_signal, remaining)) => { if got_signal { *start_time = std::time::Instant::now(); - *rusage_start = Rusage::new(); } // No signal (EOF without data): child exited without writing to // SIRUN_READY_FD. Use original timers — full process lifetime @@ -94,14 +92,13 @@ async fn run_with_instruction_count( config: &Config, read_fd: RawFd, start_time: &mut std::time::Instant, - rusage_start: &mut Rusage, ) -> Result<(ExitStatus, Option)> { use perfcnt::AbstractPerfCounter; use perfcnt::linux::{HardwareEventType, PerfCounterBuilderLinux}; if !config.instructions { return Ok(( - wait_with_ready_signal(child, read_fd, start_time, rusage_start).await?, + wait_with_ready_signal(child, read_fd, start_time).await?, None, )); } @@ -122,7 +119,6 @@ async fn run_with_instruction_count( futures::future::Either::Left((got_signal, remaining)) => { let startup = if got_signal { *start_time = std::time::Instant::now(); - *rusage_start = Rusage::new(); counter.stop()?; let val = counter.read()?; counter.start()?; @@ -151,10 +147,9 @@ async fn run_with_instruction_count( _config: &Config, read_fd: RawFd, start_time: &mut std::time::Instant, - rusage_start: &mut Rusage, ) -> Result<(ExitStatus, Option)> { Ok(( - wait_with_ready_signal(child, read_fd, start_time, rusage_start).await?, + wait_with_ready_signal(child, read_fd, start_time).await?, None, )) } @@ -172,7 +167,10 @@ async fn run_test(config: &Config, mut metrics: &mut HashMap Date: Wed, 3 Jun 2026 16:24:20 -0400 Subject: [PATCH 07/18] chore: ignore docs/superpowers/; untrack committed spec --- .gitignore | 1 + .../specs/2026-06-03-ready-signal-design.md | 99 ------------------- 2 files changed, 1 insertion(+), 99 deletions(-) delete mode 100644 docs/superpowers/specs/2026-06-03-ready-signal-design.md diff --git a/.gitignore b/.gitignore index ea8c4bf..ac339f2 100644 --- a/.gitignore +++ b/.gitignore @@ -1 +1,2 @@ +/docs/superpowers/ /target diff --git a/docs/superpowers/specs/2026-06-03-ready-signal-design.md b/docs/superpowers/specs/2026-06-03-ready-signal-design.md deleted file mode 100644 index 9b0058c..0000000 --- a/docs/superpowers/specs/2026-06-03-ready-signal-design.md +++ /dev/null @@ -1,99 +0,0 @@ -# Ready Signal Design - -**Date:** 2026-06-03 -**Status:** Approved - -## Problem - -Sirun starts measuring from the moment the benchmarked process is launched. For -interpreted-language apps (Node.js, Python, etc.), module loading and other -startup work can account for a significant portion of the measured time, -obscuring the actual benchmark signal. - -## Goal - -Allow the benchmarked app to signal when it is ready to be measured, so that -startup time is excluded from all reported metrics. - -## Design - -### Signal mechanism - -Before spawning the benchmarked command, the inner sirun process (the one that -runs per-iteration, detected by `SIRUN_ITERATION`) creates a Unix pipe. The -write-end fd number is passed to the child via the `SIRUN_READY_FD` environment -variable. The write-end is explicitly inherited by the child using -`CommandExt::fd`; all other extra fds remain close-on-exec. - -After spawning the child, the inner sirun closes its copy of the write-end and -runs an async `select!` racing two futures: - -1. **Read from the pipe read-end** — data arrives, meaning the app signaled ready. -2. **Child exits** — the process ended before signaling. - -### On signal received (case 1) - -- `start_time` (`std::time::Instant`) is reset to now. -- On Linux with `instructions: true`: the counter is stopped, its value saved - as `startup_instructions`, then restarted. The final post-ready instruction - count is `total_instructions - startup_instructions`. (Stop/restart is used - rather than reading while running, since `perfcnt` requires the counter to - be stopped before reading.) -- Only the first write to `SIRUN_READY_FD` has any effect. After the first - read, Sirun stops watching the pipe and proceeds to wait for the child to exit. - -### On child exit before signal (case 2) - -Silent fallback: Sirun uses the original `start_time` and `rusage` baseline. -No warning is emitted. The app simply did not use the feature. - -### Usage - -```js -// Node.js — after all imports and startup work -require('fs').writeSync(parseInt(process.env.SIRUN_READY_FD), 'x'); -``` - -```python -# Python — after all imports and startup work -import os -os.write(int(os.environ['SIRUN_READY_FD']), b'x') -``` - -```sh -# Shell — after startup work -echo x >&$SIRUN_READY_FD -``` - -## Metrics - -| Metric | When signal received | When no signal | -|---------------------|-------------------------------|---------------------| -| `wall.time` | Post-ready period only | Full lifetime | -| `user.time` | Full lifetime (RUSAGE_CHILDREN limitation) | Full lifetime | -| `system.time` | Full lifetime (RUSAGE_CHILDREN limitation) | Full lifetime | -| `cpu.pct.wall.time` | Full lifetime (derived from user+system) | Full lifetime | -| `instructions` | Post-ready only (Linux) | Full lifetime | -| `max.res.size` | Full lifetime (not reset) | Full lifetime | - -`max.res.size`, `user.time`, `system.time`, and `cpu.pct.wall.time` always -reflect the full process lifetime. `RUSAGE_CHILDREN` (used for the rusage -metrics) only updates after a child exits and is waited for, so it cannot be -sampled mid-run in a meaningful way. - -## Config changes - -No new config fields. The pipe is always created and `SIRUN_READY_FD` is always -set in the child's environment. Apps opt in by writing to the fd. - -## Implementation notes - -- Pipe creation and the `select!` live in `run_test()` in `src/main.rs`. -- `run_cmd()` in `src/subproc.rs` needs a new optional parameter (or a - separate variant) to accept an fd to explicitly inherit via - `std::os::unix::process::CommandExt::fd`. -- The Linux instruction counter path in `run_with_instruction_count()` needs - to accept a signal channel; on signal it stops the counter, saves the value, - and restarts it. The final reported value is `total - startup_instructions`. -- `SIRUN_READY_FD` should be documented in the README alongside the other - environment variables. From d40c1bc5de78963f031b783ab715cd0f16a8b5b4 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Wed, 3 Jun 2026 16:53:13 -0400 Subject: [PATCH 08/18] feat: add read_child_cpu_us for mid-run CPU snapshot (Linux + macOS) --- src/rusage.rs | 112 ++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 112 insertions(+) diff --git a/src/rusage.rs b/src/rusage.rs index 150eafa..32e244b 100644 --- a/src/rusage.rs +++ b/src/rusage.rs @@ -45,3 +45,115 @@ impl Sub for Rusage { } } } + +/// Returns the CPU time (user_µs, system_µs) of a running process by reading +/// `/proc/{pid}/stat`. Returns `None` if the file cannot be read or parsed. +#[cfg(target_os = "linux")] +pub(crate) fn read_child_cpu_us(pid: u32) -> Option<(f64, f64)> { + let contents = std::fs::read_to_string(format!("/proc/{}/stat", pid)).ok()?; + // The second field (process name) is wrapped in parentheses and may contain + // spaces. Find the last ')' to reliably skip past it. + let after_name = contents.rfind(')')? + 1; + let fields: Vec<&str> = contents[after_name..].split_whitespace().collect(); + // After ')': state(0) ppid(1) pgrp(2) session(3) tty_nr(4) tpgid(5) + // flags(6) minflt(7) cminflt(8) majflt(9) cmajflt(10) utime(11) stime(12) + let utime_jiffies: u64 = fields.get(11)?.parse().ok()?; + let stime_jiffies: u64 = fields.get(12)?.parse().ok()?; + let ticks_raw = unsafe { nix::libc::sysconf(nix::libc::_SC_CLK_TCK) }; + if ticks_raw <= 0 { + return None; + } + let ticks = ticks_raw as f64; + Some(( + utime_jiffies as f64 * 1_000_000.0 / ticks, + stime_jiffies as f64 * 1_000_000.0 / ticks, + )) +} + +/// Returns the CPU time (user_µs, system_µs) of a running process via +/// `proc_pidinfo(PROC_PIDTASKINFO)`. Returns `None` on failure. +#[cfg(target_os = "macos")] +pub(crate) fn read_child_cpu_us(pid: u32) -> Option<(f64, f64)> { + const PROC_PIDTASKINFO: nix::libc::c_int = 4; + + #[repr(C)] + struct ProcTaskInfo { + pti_virtual_size: u64, + pti_resident_size: u64, + pti_total_user: u64, // nanoseconds — XNU bsd/kern/proc_info.c fill_taskprocinfo() + pti_total_system: u64, // nanoseconds — XNU bsd/kern/proc_info.c fill_taskprocinfo() + pti_threads_user: u64, + pti_threads_system: u64, + pti_policy: i32, + pti_faults: i32, + pti_pageins: i32, + pti_cow_faults: i32, + pti_messages_sent: i32, + pti_messages_received: i32, + pti_syscalls_mach: i32, + pti_syscalls_unix: i32, + pti_csw: i32, + pti_threadnum: i32, + pti_numrunning: i32, + pti_priority: i32, + } + + extern "C" { + fn proc_pidinfo( + pid: nix::libc::c_int, + flavor: nix::libc::c_int, + arg: u64, + buffer: *mut nix::libc::c_void, + buffersize: nix::libc::c_int, + ) -> nix::libc::c_int; + } + + let mut info = std::mem::MaybeUninit::::zeroed(); + let ret = unsafe { + proc_pidinfo( + pid as nix::libc::c_int, + PROC_PIDTASKINFO, + 0, + info.as_mut_ptr() as *mut nix::libc::c_void, + std::mem::size_of::() as nix::libc::c_int, + ) + }; + if ret < std::mem::size_of::() as nix::libc::c_int { + return None; + } + let info = unsafe { info.assume_init() }; + // Convert nanoseconds to microseconds. + Some(( + info.pti_total_user as f64 / 1_000.0, + info.pti_total_system as f64 / 1_000.0, + )) +} + +#[cfg(not(any(target_os = "linux", target_os = "macos")))] +pub(crate) fn read_child_cpu_us(_pid: u32) -> Option<(f64, f64)> { + None +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn read_child_cpu_us_returns_some_for_current_process() { + let pid = std::process::id(); + let result = read_child_cpu_us(pid); + #[cfg(any(target_os = "linux", target_os = "macos"))] + assert!(result.is_some(), "expected CPU reading for pid {}", pid); + #[cfg(not(any(target_os = "linux", target_os = "macos")))] + let _ = result; + } + + #[test] + fn read_child_cpu_us_values_are_non_negative() { + let pid = std::process::id(); + if let Some((utime, stime)) = read_child_cpu_us(pid) { + assert!(utime >= 0.0); + assert!(stime >= 0.0); + } + } +} From 01ffbd30b8e292580d56111deda1734f4329fee5 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Wed, 3 Jun 2026 16:57:41 -0400 Subject: [PATCH 09/18] feat: subtract startup CPU from user.time/system.time at ready signal --- src/main.rs | 76 ++++++++++++++++++++++++++++++----------------------- 1 file changed, 43 insertions(+), 33 deletions(-) diff --git a/src/main.rs b/src/main.rs index 6b5c6b2..f834cca 100644 --- a/src/main.rs +++ b/src/main.rs @@ -66,23 +66,30 @@ async fn wait_with_ready_signal( child: &mut Child, read_fd: RawFd, start_time: &mut std::time::Instant, -) -> Result { +) -> Result<(ExitStatus, Option<(f64, f64)>)> { + // Fetch pid before child.status() borrows child mutably for the future's + // lifetime. + let pid = child.id(); let pipe_fut = read_one_byte(read_fd); let status_fut = child.status(); futures::pin_mut!(pipe_fut, status_fut); match futures::future::select(pipe_fut, status_fut).await { futures::future::Either::Left((got_signal, remaining)) => { - if got_signal { + let startup_cpu = if got_signal { + let cpu = read_child_cpu_us(pid); *start_time = std::time::Instant::now(); - } - // No signal (EOF without data): child exited without writing to - // SIRUN_READY_FD. Use original timers — full process lifetime - // is measured. - remaining.await.map_err(Into::into) + cpu + } else { + // No signal (EOF without data): child exited without writing to + // SIRUN_READY_FD. Use original timers — full process lifetime + // is measured. + None + }; + Ok((remaining.await?, startup_cpu)) } // Child exited before any data was written to the pipe. // Use original timers — full process lifetime is measured. - futures::future::Either::Right((status, _)) => status.map_err(Into::into), + futures::future::Either::Right((status, _)) => Ok((status?, None)), } } @@ -92,15 +99,14 @@ async fn run_with_instruction_count( config: &Config, read_fd: RawFd, start_time: &mut std::time::Instant, -) -> Result<(ExitStatus, Option)> { +) -> Result<(ExitStatus, Option, Option<(f64, f64)>)> { use perfcnt::AbstractPerfCounter; use perfcnt::linux::{HardwareEventType, PerfCounterBuilderLinux}; if !config.instructions { - return Ok(( - wait_with_ready_signal(child, read_fd, start_time).await?, - None, - )); + let (status, startup_cpu) = + wait_with_ready_signal(child, read_fd, start_time).await?; + return Ok((status, None, startup_cpu)); } let pid = child.id(); @@ -114,31 +120,32 @@ async fn run_with_instruction_count( let status_fut = child.status(); futures::pin_mut!(pipe_fut, status_fut); - let (startup_instructions, status) = + let (startup_instructions, startup_cpu, status) = match futures::future::select(pipe_fut, status_fut).await { futures::future::Either::Left((got_signal, remaining)) => { - let startup = if got_signal { + let (startup_instr, cpu) = if got_signal { + let cpu = read_child_cpu_us(pid); *start_time = std::time::Instant::now(); counter.stop()?; let val = counter.read()?; counter.start()?; - val + (val, cpu) } else { - // Child closed write end (exited) without writing to - // SIRUN_READY_FD. Use original timers and count all - // instructions from process start. - 0 + // Child closed write end without writing to SIRUN_READY_FD. + // Use original timers and count all instructions from + // process start. + (0, None) }; - (startup, remaining.await?) + (startup_instr, cpu, remaining.await?) } // Child exited before any data arrived on the pipe. // Use original timers and count all instructions from process start. - futures::future::Either::Right((status, _)) => (0, status?), + futures::future::Either::Right((status, _)) => (0, None, status?), }; counter.stop()?; let total = counter.read()?; - Ok((status, Some(total - startup_instructions))) + Ok((status, Some(total - startup_instructions), startup_cpu)) } #[cfg(not(target_os = "linux"))] @@ -147,11 +154,10 @@ async fn run_with_instruction_count( _config: &Config, read_fd: RawFd, start_time: &mut std::time::Instant, -) -> Result<(ExitStatus, Option)> { - Ok(( - wait_with_ready_signal(child, read_fd, start_time).await?, - None, - )) +) -> Result<(ExitStatus, Option, Option<(f64, f64)>)> { + let (status, startup_cpu) = + wait_with_ready_signal(child, read_fd, start_time).await?; + Ok((status, None, startup_cpu)) } async fn run_test(config: &Config, mut metrics: &mut HashMap) -> Result<()> { @@ -167,15 +173,15 @@ async fn run_test(config: &Config, mut metrics: &mut HashMap Date: Wed, 3 Jun 2026 17:05:41 -0400 Subject: [PATCH 10/18] test: verify cpu.pct.wall.time stays bounded with CPU-intensive ready signal --- examples/ready-signal-cpu.json | 3 +++ tests/examples.rs | 26 ++++++++++++++++++++++++++ 2 files changed, 29 insertions(+) create mode 100644 examples/ready-signal-cpu.json diff --git a/examples/ready-signal-cpu.json b/examples/ready-signal-cpu.json new file mode 100644 index 0000000..7d1976e --- /dev/null +++ b/examples/ready-signal-cpu.json @@ -0,0 +1,3 @@ +{ + "run": "bash -c 'for i in $(seq 1 300000); do :; done; echo x >&$SIRUN_READY_FD; sleep 0.3'" +} diff --git a/tests/examples.rs b/tests/examples.rs index 6cdbf23..851f008 100644 --- a/tests/examples.rs +++ b/tests/examples.rs @@ -337,3 +337,29 @@ fn ready_signal_fallback_when_no_signal() { == 1 }); } + +#[test] +#[serial] +fn ready_signal_cpu_pct_bounded() { + json_has!( + "./examples/ready-signal-cpu.json", + |map: &serde_yaml::Mapping| { + let iter = map + .get(&"iterations".into()) + .unwrap() + .as_sequence() + .unwrap()[0] + .as_mapping() + .unwrap(); + let cpu_pct = iter + .get(&"cpu.pct.wall.time".into()) + .unwrap() + .as_f64() + .unwrap(); + // Without the fix, user.time covers the full CPU-intensive startup + // while wall.time covers only the post-ready period (near zero), + // making cpu.pct.wall.time >> 100%. With the fix it must stay <= 100%. + cpu_pct <= 100.0 + } + ); +} From 871deedd95caeb9c51f184654695f5179c084407 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Thu, 4 Jun 2026 13:17:44 -0400 Subject: [PATCH 11/18] refactor: replace futures select/Either with sequential pipe read The pipe already signals child exit via EOF when the write end closes, so racing the pipe against child.status() is unnecessary. Sequential await is simpler and removes the futures dependency entirely. --- Cargo.lock | 94 ++++------------------------------------------------- Cargo.toml | 1 - src/main.rs | 73 +++++++++++++---------------------------- 3 files changed, 30 insertions(+), 138 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 7ca907d..f03abba 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -38,7 +38,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a3203e79f4dd9bdda415ed03cf14dae5a2bf775c683a00f94e9cd1faf0f596e5" dependencies = [ "quote", - "syn 1.0.60", + "syn", ] [[package]] @@ -316,7 +316,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "e8f45d9ad417bcef4817d614a501ab55cdd96a6fdb24f49aab89a54acfd66b19" dependencies = [ "quote", - "syn 1.0.60", + "syn", ] [[package]] @@ -379,21 +379,6 @@ version = "0.1.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a06f77d526c1a601b7c4cdd98f54b5eaabffc14d5f2f0296febdc7f357c6d3ba" -[[package]] -name = "futures" -version = "0.3.31" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "65bc07b1a8bc7c85c5f2e110c476c7389b4554ba72af57d8445ea63a576b0876" -dependencies = [ - "futures-channel", - "futures-core", - "futures-executor", - "futures-io", - "futures-sink", - "futures-task", - "futures-util", -] - [[package]] name = "futures-channel" version = "0.3.32" @@ -401,7 +386,6 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "07bbe89c50d7a535e539b8c17bc0b49bdb77747034daa8087407d655f3f7cc1d" dependencies = [ "futures-core", - "futures-sink", ] [[package]] @@ -410,17 +394,6 @@ version = "0.3.32" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "7e3450815272ef58cec6d564423f6e755e25379b217b0bc688e295ba24df6b1d" -[[package]] -name = "futures-executor" -version = "0.3.31" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1e28d1d997f585e54aebc3f97d39e72338912123a67330d723fdbb564d646c9f" -dependencies = [ - "futures-core", - "futures-task", - "futures-util", -] - [[package]] name = "futures-io" version = "0.3.32" @@ -442,47 +415,6 @@ dependencies = [ "waker-fn", ] -[[package]] -name = "futures-macro" -version = "0.3.31" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "162ee34ebcb7c64a8abebc059ce0fee27c2262618d7b60ed8faf72fef13c3650" -dependencies = [ - "proc-macro2", - "quote", - "syn 2.0.117", -] - -[[package]] -name = "futures-sink" -version = "0.3.32" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c39754e157331b013978ec91992bde1ac089843443c49cbc7f46150b0fad0893" - -[[package]] -name = "futures-task" -version = "0.3.32" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "037711b3d59c33004d3856fbdc83b99d4ff37a24768fa1be9ce3538a1cde4393" - -[[package]] -name = "futures-util" -version = "0.3.31" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9fa08315bb612088cc391249efdc3bc77536f16c91f6cf495e6fbe85b20a4a81" -dependencies = [ - "futures-channel", - "futures-core", - "futures-io", - "futures-macro", - "futures-sink", - "futures-task", - "memchr", - "pin-project-lite", - "pin-utils", - "slab", -] - [[package]] name = "getrandom" version = "0.2.8" @@ -1014,7 +946,7 @@ checksum = "1800f7693e94e186f5e25a28291ae1570da908aff7d97a095dec1e56ff99069b" dependencies = [ "proc-macro2", "quote", - "syn 1.0.60", + "syn", ] [[package]] @@ -1060,7 +992,7 @@ checksum = "b2acd6defeddb41eb60bb468f8825d0cfd0c2a76bc03bfd235b6a1dc4f6a1ad5" dependencies = [ "proc-macro2", "quote", - "syn 1.0.60", + "syn", ] [[package]] @@ -1102,7 +1034,6 @@ dependencies = [ "assert_cmd", "async-std", "caps", - "futures", "indexmap 2.9.0", "lazy_static", "nix", @@ -1150,17 +1081,6 @@ dependencies = [ "unicode-xid", ] -[[package]] -name = "syn" -version = "2.0.117" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "e665b8803e7b1d2a727f4023456bbbbe74da67099c585258af0ad9c5013b9b99" -dependencies = [ - "proc-macro2", - "quote", - "unicode-ident", -] - [[package]] name = "tempdir" version = "0.3.7" @@ -1188,7 +1108,7 @@ checksum = "982d17546b47146b28f7c22e3d08465f6b8903d0ea13c1660d9d84a6e7adcdbb" dependencies = [ "proc-macro2", "quote", - "syn 1.0.60", + "syn", ] [[package]] @@ -1281,7 +1201,7 @@ dependencies = [ "log", "proc-macro2", "quote", - "syn 1.0.60", + "syn", "wasm-bindgen-shared", ] @@ -1315,7 +1235,7 @@ checksum = "cc053ec74d454df287b9374ee8abb36ffd5acb95ba87da3ba5b7d3fe20eb401e" dependencies = [ "proc-macro2", "quote", - "syn 1.0.60", + "syn", "wasm-bindgen-backend", "wasm-bindgen-shared", ] diff --git a/Cargo.toml b/Cargo.toml index 3bd8f0a..695cd91 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -22,7 +22,6 @@ serde = { version = "1.0.124", features = ["derive"] } anyhow = "<=1.0.48" which = "4.0.2" indexmap = { version = "2.9.0", features = ["serde"] } -futures = "0.3" [target.'cfg(target_os = "linux")'.dependencies] perfcnt = "0.8.0" diff --git a/src/main.rs b/src/main.rs index f834cca..93bf3d8 100644 --- a/src/main.rs +++ b/src/main.rs @@ -67,30 +67,17 @@ async fn wait_with_ready_signal( read_fd: RawFd, start_time: &mut std::time::Instant, ) -> Result<(ExitStatus, Option<(f64, f64)>)> { - // Fetch pid before child.status() borrows child mutably for the future's - // lifetime. - let pid = child.id(); - let pipe_fut = read_one_byte(read_fd); - let status_fut = child.status(); - futures::pin_mut!(pipe_fut, status_fut); - match futures::future::select(pipe_fut, status_fut).await { - futures::future::Either::Left((got_signal, remaining)) => { - let startup_cpu = if got_signal { - let cpu = read_child_cpu_us(pid); - *start_time = std::time::Instant::now(); - cpu - } else { - // No signal (EOF without data): child exited without writing to - // SIRUN_READY_FD. Use original timers — full process lifetime - // is measured. - None - }; - Ok((remaining.await?, startup_cpu)) - } - // Child exited before any data was written to the pipe. - // Use original timers — full process lifetime is measured. - futures::future::Either::Right((status, _)) => Ok((status?, None)), - } + // Returns true if the app wrote to SIRUN_READY_FD; false if it exited + // without signaling (parent closed write end, so child exit → EOF). + let got_signal = read_one_byte(read_fd).await; + let startup_cpu = if got_signal { + let cpu = read_child_cpu_us(child.id()); + *start_time = std::time::Instant::now(); + cpu + } else { + None + }; + Ok((child.status().await?, startup_cpu)) } #[cfg(target_os = "linux")] @@ -116,33 +103,19 @@ async fn run_with_instruction_count( .finish()?; counter.start()?; - let pipe_fut = read_one_byte(read_fd); - let status_fut = child.status(); - futures::pin_mut!(pipe_fut, status_fut); - - let (startup_instructions, startup_cpu, status) = - match futures::future::select(pipe_fut, status_fut).await { - futures::future::Either::Left((got_signal, remaining)) => { - let (startup_instr, cpu) = if got_signal { - let cpu = read_child_cpu_us(pid); - *start_time = std::time::Instant::now(); - counter.stop()?; - let val = counter.read()?; - counter.start()?; - (val, cpu) - } else { - // Child closed write end without writing to SIRUN_READY_FD. - // Use original timers and count all instructions from - // process start. - (0, None) - }; - (startup_instr, cpu, remaining.await?) - } - // Child exited before any data arrived on the pipe. - // Use original timers and count all instructions from process start. - futures::future::Either::Right((status, _)) => (0, None, status?), - }; + let got_signal = read_one_byte(read_fd).await; + let (startup_instructions, startup_cpu) = if got_signal { + let cpu = read_child_cpu_us(pid); + *start_time = std::time::Instant::now(); + counter.stop()?; + let val = counter.read()?; + counter.start()?; + (val, cpu) + } else { + (0, None) + }; + let status = child.status().await?; counter.stop()?; let total = counter.read()?; Ok((status, Some(total - startup_instructions), startup_cpu)) From 4fa2e8699009cb184e4ab968bea7f5bfcc12035b Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Thu, 4 Jun 2026 13:28:16 -0400 Subject: [PATCH 12/18] refactor: use async_std::fs::File instead of spawn_blocking in read_one_byte --- src/main.rs | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/src/main.rs b/src/main.rs index 93bf3d8..07942ed 100644 --- a/src/main.rs +++ b/src/main.rs @@ -54,12 +54,10 @@ async fn test_timeout(timeout: u64) { } async fn read_one_byte(fd: RawFd) -> bool { - async_std::task::spawn_blocking(move || { - let mut buf = [0u8; 1]; - let mut f = unsafe { std::fs::File::from_raw_fd(fd) }; - matches!(std::io::Read::read(&mut f, &mut buf), Ok(n) if n > 0) - }) - .await + use async_std::io::ReadExt; + let mut buf = [0u8; 1]; + let mut f = unsafe { async_std::fs::File::from_raw_fd(fd) }; + f.read(&mut buf).await.map(|n| n > 0).unwrap_or(false) } async fn wait_with_ready_signal( From afee8307e13e7081e8920cdc1ea8f97621d51ae1 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Thu, 4 Jun 2026 13:38:42 -0400 Subject: [PATCH 13/18] revert: use spawn_blocking in read_one_byte (async_std::fs::File caused CI flakiness on macOS) async_std::fs::File on macOS uses kqueue-based I/O: when the pipe event fires, the async task is rescheduled through the executor before resuming. That extra scheduling hop means proc_pidinfo is called slightly later than with spawn_blocking, which uses a dedicated OS thread that calls proc_pidinfo synchronously right after the read returns with no scheduler hop in between. On a loaded CI runner that window is large enough for the process state to change, causing proc_pidinfo to return None and the CPU subtraction to be skipped. --- src/main.rs | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/src/main.rs b/src/main.rs index 07942ed..93bf3d8 100644 --- a/src/main.rs +++ b/src/main.rs @@ -54,10 +54,12 @@ async fn test_timeout(timeout: u64) { } async fn read_one_byte(fd: RawFd) -> bool { - use async_std::io::ReadExt; - let mut buf = [0u8; 1]; - let mut f = unsafe { async_std::fs::File::from_raw_fd(fd) }; - f.read(&mut buf).await.map(|n| n > 0).unwrap_or(false) + async_std::task::spawn_blocking(move || { + let mut buf = [0u8; 1]; + let mut f = unsafe { std::fs::File::from_raw_fd(fd) }; + matches!(std::io::Read::read(&mut f, &mut buf), Ok(n) if n > 0) + }) + .await } async fn wait_with_ready_signal( From 104a61d8f9c7b10fce4c9fe75ea6b3382fedb783 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Thu, 4 Jun 2026 14:20:52 -0400 Subject: [PATCH 14/18] test: measure async_std::fs::File reliability 100x on CI Co-Authored-By: Claude Sonnet 4.6 --- src/main.rs | 10 +++----- tests/examples.rs | 63 +++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 67 insertions(+), 6 deletions(-) diff --git a/src/main.rs b/src/main.rs index 93bf3d8..07942ed 100644 --- a/src/main.rs +++ b/src/main.rs @@ -54,12 +54,10 @@ async fn test_timeout(timeout: u64) { } async fn read_one_byte(fd: RawFd) -> bool { - async_std::task::spawn_blocking(move || { - let mut buf = [0u8; 1]; - let mut f = unsafe { std::fs::File::from_raw_fd(fd) }; - matches!(std::io::Read::read(&mut f, &mut buf), Ok(n) if n > 0) - }) - .await + use async_std::io::ReadExt; + let mut buf = [0u8; 1]; + let mut f = unsafe { async_std::fs::File::from_raw_fd(fd) }; + f.read(&mut buf).await.map(|n| n > 0).unwrap_or(false) } async fn wait_with_ready_signal( diff --git a/tests/examples.rs b/tests/examples.rs index 851f008..c5c8316 100644 --- a/tests/examples.rs +++ b/tests/examples.rs @@ -363,3 +363,66 @@ fn ready_signal_cpu_pct_bounded() { } ); } + +#[test] +#[serial] +fn ready_signal_cpu_pct_100x() { + let mut passes = 0u32; + let mut failures = 0u32; + let mut cpu_pcts: Vec = Vec::new(); + + for _ in 0..100 { + let output = assert_cmd::Command::cargo_bin("sirun") + .unwrap() + .arg("./examples/ready-signal-cpu.json") + .env("SIRUN_NO_STDIO", "1") + .output() + .unwrap(); + + if output.status.success() { + if let Ok(val) = + serde_yaml::from_slice::(&output.stdout) + { + if let Some(cpu_pct) = val + .as_mapping() + .and_then(|m| m.get(&"iterations".into())) + .and_then(|v| v.as_sequence()) + .and_then(|s| s.get(0)) + .and_then(|v| v.as_mapping()) + .and_then(|m| m.get(&"cpu.pct.wall.time".into())) + .and_then(|v| v.as_f64()) + { + cpu_pcts.push(cpu_pct); + if cpu_pct <= 100.0 { + passes += 1; + } else { + failures += 1; + } + } else { + failures += 1; + } + } else { + failures += 1; + } + } else { + failures += 1; + } + } + + let max_pct = cpu_pcts + .iter() + .cloned() + .fold(f64::NEG_INFINITY, f64::max); + eprintln!( + "async_std::fs::File 100x: {}/100 passed, \ + max cpu.pct.wall.time = {:.1}%", + passes, max_pct + ); + assert!( + passes >= 95, + "async_std::fs::File: {}/100 passed \ + (max cpu.pct.wall.time = {:.1}%)", + passes, + max_pct + ); +} From af40430aabb4088da81d331148b2e15aa861c1f8 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Thu, 4 Jun 2026 14:57:54 -0400 Subject: [PATCH 15/18] fix: prevent bash exec-optimization in ready-signal-cpu fixture --- examples/ready-signal-cpu.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/examples/ready-signal-cpu.json b/examples/ready-signal-cpu.json index 7d1976e..5ee3094 100644 --- a/examples/ready-signal-cpu.json +++ b/examples/ready-signal-cpu.json @@ -1,3 +1,3 @@ { - "run": "bash -c 'for i in $(seq 1 300000); do :; done; echo x >&$SIRUN_READY_FD; sleep 0.3'" + "run": "bash -c 'for i in $(seq 1 300000); do :; done; echo x >&$SIRUN_READY_FD; sleep 0.3; :'" } From 97480cf7a2a012b8529fd2b681566ee7b2bf3df1 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Thu, 4 Jun 2026 15:15:40 -0400 Subject: [PATCH 16/18] fix: use brace expansion to keep CPU in bash process (not seq subprocess) --- examples/ready-signal-cpu.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/examples/ready-signal-cpu.json b/examples/ready-signal-cpu.json index 5ee3094..52dfa57 100644 --- a/examples/ready-signal-cpu.json +++ b/examples/ready-signal-cpu.json @@ -1,3 +1,3 @@ { - "run": "bash -c 'for i in $(seq 1 300000); do :; done; echo x >&$SIRUN_READY_FD; sleep 0.3; :'" + "run": "bash -c 'for i in {1..300000}; do :; done; echo x >&$SIRUN_READY_FD; sleep 0.3; :'" } From ccbadd4210929b025462df4ee1f3f4810ce55732 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Thu, 4 Jun 2026 15:36:55 -0400 Subject: [PATCH 17/18] fix: use subshell (sleep 0.3) so parent bash keeps its CPU history --- examples/ready-signal-cpu.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/examples/ready-signal-cpu.json b/examples/ready-signal-cpu.json index 52dfa57..433c17a 100644 --- a/examples/ready-signal-cpu.json +++ b/examples/ready-signal-cpu.json @@ -1,3 +1,3 @@ { - "run": "bash -c 'for i in {1..300000}; do :; done; echo x >&$SIRUN_READY_FD; sleep 0.3; :'" + "run": "bash -c 'for i in {1..300000}; do :; done; echo x >&$SIRUN_READY_FD; (sleep 0.3)'" } From 143ad7ab9d4dd0b5ddfe6bdf8c765de6eb7154f4 Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Thu, 4 Jun 2026 15:58:11 -0400 Subject: [PATCH 18/18] fix: use python3 fixture to avoid bash subprocess CPU leaking into RUSAGE_CHILDREN --- examples/ready-signal-cpu.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/examples/ready-signal-cpu.json b/examples/ready-signal-cpu.json index 433c17a..6f4627c 100644 --- a/examples/ready-signal-cpu.json +++ b/examples/ready-signal-cpu.json @@ -1,3 +1,3 @@ { - "run": "bash -c 'for i in {1..300000}; do :; done; echo x >&$SIRUN_READY_FD; (sleep 0.3)'" + "run": "python3 -c \"import os,time; [None for _ in range(1000000)]; os.write(int(os.environ['SIRUN_READY_FD']),b'x'); time.sleep(0.3)\"" }