Fix most of the review comments

Signed-off-by: Tej Chajed <[email protected]>

benchmarking/src/lib.rs

@@ -11,6 +11,6 @@
 #![allow(rustdoc::private_intra_doc_links)]
 #![deny(rustdoc::broken_intra_doc_links)]
 
-pub mod result;
+pub mod measurement;
 pub mod run;
 pub mod time_bench;

benchmarking/src/result.rs → benchmarking/src/measurement.rs

@@ -23,9 +23,9 @@ pub struct RunMeasurement {
     pub self_user_time: Duration,
     /// Max memory usage (RSS) in bytes
     pub max_mem_bytes: usize,
-    /// True if the run was killed early due to a timeout.
+    /// Whether the run was killed early due to a timeout.
     pub timed_out: bool,
-    /// True if the run was successful
+    /// Whether the run was successful
     pub success: bool,
 }
 
@@ -35,8 +35,8 @@ impl RunMeasurement {
         self.max_mem_bytes / 1024 / 1024
     }
 
-    /// Time spent in solver.
-    pub fn solver_time(&self) -> Duration {
+    /// Time spent in subprocesses (eg, SMT solver).
+    pub fn subprocess_time(&self) -> Duration {
         self.user_time.saturating_sub(self.self_user_time)
     }
 
@@ -48,7 +48,7 @@ impl RunMeasurement {
             timed_out_msg = if self.timed_out { " (timed out)" } else { "" }
         );
         println!("  user:   {:0.1}s", self.user_time.as_secs_f64());
-        println!("  solver: {:0.1}s", self.solver_time().as_secs_f64());
+        println!("  solver: {:0.1}s", self.subprocess_time().as_secs_f64());
         println!("  sys:    {:0.1}s", self.sys_time.as_secs_f64());
         println!("max mem: {}MB", self.max_mem_mb());
     }

benchmarking/src/run.rs

@@ -1,12 +1,12 @@
 // Copyright 2022-2023 VMware, Inc.
 // SPDX-License-Identifier: BSD-2-Clause
 
-//! Library for running and reporting benchmark results.
+//! Library for running and reporting benchmark measurements.
 
 use std::{collections::HashMap, ffi::OsStr, path::PathBuf, time::Duration};
 
 use crate::{
-    result::RunMeasurement,
+    measurement::RunMeasurement,
     time_bench::{Time, REPO_ROOT_PATH},
 };
 
@@ -27,7 +27,18 @@ pub struct BenchmarkMeasurement {
 }
 
 impl BenchmarkMeasurement {
-    /// Run flyvy on a single benchmark.
+    /// Run flyvy on a single benchmark, isolated to its own process.
+    ///
+    /// command + args form the arguments to temporal-verifier. These are split
+    /// only for display purposes in the table; `command` is something like
+    /// `infer qalpha` while `args` has other configuration and quantifiers for
+    /// each sort, for example.
+    ///
+    /// file is added to the end of the argument list and also becomes a
+    /// separate column in the results.
+    ///
+    /// time_limit is a maximum time to wait for the benchmark before killing
+    /// it.
     pub fn run(
         command: Vec<String>,
         args: Vec<String>,
@@ -39,7 +50,6 @@ impl BenchmarkMeasurement {
         timer.args(&command);
         timer.args(&args);
         timer.arg(&file);
-        // eprintln!("{}", timer.cmdline());
         let measurement = timer.run().expect("error getting timing");
         BenchmarkMeasurement {
             command,
@@ -85,8 +95,8 @@ impl BenchmarkMeasurement {
             format!("{}", file_name.display()),
             format!("{}", self.success()),
             format!("{:0.1}", self.measurement.real_time.as_secs_f64()),
-            format!("{:0.1}", self.measurement.solver_time().as_secs_f64()),
-            format!("{}MB", self.measurement.max_mem_bytes / 1024 / 1024),
+            format!("{:0.1}", self.measurement.subprocess_time().as_secs_f64()),
+            format!("{}MB", self.measurement.max_mem_mb()),
             format!("{}", self.params),
         ]
     }

benchmarking/src/time_bench.rs

@@ -30,7 +30,7 @@ use nix::{
 };
 use process_sync::{SharedCondvar, SharedMutex};
 
-use crate::result::RunMeasurement;
+use crate::measurement::RunMeasurement;
 
 /// The `time` utility runs a benchmark, optionally kills it after a timeout,
 /// and gathers resource usage statistics.
@@ -53,7 +53,9 @@ pub struct Time {
     pub args: Vec<OsString>,
 }
 
-/// Get the temporal-verifier root path. Only works when compiled from source.
+/// Get the temporal-verifier root path.
+/// TODO: Only works when using a binary compiled locally. Will need to fix when
+/// distributing a precompiled binary.
 #[allow(non_snake_case)]
 pub fn REPO_ROOT_PATH() -> &'static Path {
     Path::new(env!("CARGO_MANIFEST_DIR"))
@@ -84,23 +86,21 @@ where
         .into_iter()
         .map(|s| s.as_ref().to_owned())
         .collect::<Vec<_>>();
-    let child = Command::new("cargo")
+    let status = Command::new("cargo")
         .arg("--quiet")
         .args(&args)
         .stdin(Stdio::null())
         .stdout(Stdio::null())
         .stderr(Stdio::inherit())
         .current_dir(REPO_ROOT_PATH())
-        .spawn();
-    match child {
-        Ok(mut child) => {
-            if let Ok(r) = child.wait() {
-                if !r.success() {
-                    eprintln!(
-                        "cargo {} failed",
-                        args.join(OsStr::new(" ")).to_string_lossy()
-                    );
-                }
+        .status();
+    match status {
+        Ok(status) => {
+            if !status.success() {
+                eprintln!(
+                    "cargo {} failed",
+                    args.join(OsStr::new(" ")).to_string_lossy()
+                );
             }
         }
         Err(err) => {
@@ -134,7 +134,7 @@ fn time_val_to_duration(time: TimeVal) -> Duration {
 }
 
 impl RawRunMeasurement {
-    fn into_result(self) -> RunMeasurement {
+    fn into_measurement(self) -> RunMeasurement {
         RunMeasurement {
             real_time: self.real_time,
             user_time: time_val_to_duration(self.usage.user_time()),
@@ -148,7 +148,7 @@ impl RawRunMeasurement {
 }
 
 impl Time {
-    fn get_child_results(&self, child: i32) -> Result<RawRunMeasurement, io::Error> {
+    fn get_child_measurements(&self, child: i32) -> Result<RawRunMeasurement, io::Error> {
         let child = Pid::from_raw(child);
         let start = Instant::now();
         let timeout = Arc::new(Mutex::new(false));
@@ -179,13 +179,14 @@ impl Time {
             _ => None,
         };
         let real_time = start.elapsed();
+        let timed_out = *timeout.lock().unwrap();
         let usage = getrusage(UsageWho::RUSAGE_CHILDREN)?;
         let self_usage = getrusage(UsageWho::RUSAGE_SELF)?;
         let measurement = RawRunMeasurement {
             real_time,
             usage,
             self_usage,
-            timed_out: *timeout.lock().unwrap(),
+            timed_out,
             status,
             signal,
         };
@@ -200,20 +201,23 @@ impl Time {
         match fork::fork() {
             Ok(Fork::Parent(child)) => {
                 cvar.wait(&mut lock).unwrap();
-                let results = self.get_child_results(child)?;
-                let parsed = results.clone().into_result();
+                let measurements = self.get_child_measurements(child)?;
+                let parsed = measurements.clone().into_measurement();
                 if self.json {
                     println!("{}", parsed.to_json());
                 } else {
                     parsed.print();
                 }
-                if results.timed_out {
-                    return Ok(ExitCode::SUCCESS);
+                // timed_out is true if and only if the timeout thread triggers
+                // (even if this happens after the child exits)
+                if measurements.timed_out {
+                    // to match behavior of `timeout(1)`
+                    return Ok(ExitCode::from(124u8));
                 }
-                if results.signal.is_some() {
+                if measurements.signal.is_some() {
                     return Ok(ExitCode::FAILURE);
                 }
-                if let Some(code) = results.status {
+                if let Some(code) = measurements.status {
                     return Ok(ExitCode::from(code as u8));
                 }
                 Ok(ExitCode::SUCCESS)