Rollup merge of #137077 - Kobzol:citool-test-metrics, r=marcoieni

Postprocess bootstrap metrics into GitHub job summary

This PR adds a postprocessing step to each CI job that writes the build and test step bootstrap metrics into [GitHub job summary](https://github.blog/news-insights/product-news/supercharging-github-actions-with-job-summaries/). You can see an example result for dist and test jobs [here](1361949548).

r? ``@ghost``

try-job: dist-x86_64-illumos
try-job: x86_64-gnu

.github/workflows/ci.yml

@@ -182,6 +182,13 @@ jobs:
       - name: show the current environment
         run: src/ci/scripts/dump-environment.sh
 
+      # Pre-build citool before the following step uninstalls rustup
+      # Build is into the build directory, to avoid modifying sources
+      - name: build citool
+        run: |
+          cd src/ci/citool
+          CARGO_TARGET_DIR=../../../build/citool cargo build
+
       - name: run the build
         # Redirect stderr to stdout to avoid reordering the two streams in the GHA logs.
         run: src/ci/scripts/run-build-from-ci.sh 2>&1
@@ -218,6 +225,16 @@ jobs:
         # erroring about invalid credentials instead.
         if: github.event_name == 'push' || env.DEPLOY == '1' || env.DEPLOY_ALT == '1'
 
+      - name: postprocess metrics into the summary
+        run: |
+          if [ -f build/metrics.json ]; then
+            ./build/citool/debug/citool postprocess-metrics build/metrics.json ${GITHUB_STEP_SUMMARY}
+          elif [ -f obj/build/metrics.json ]; then
+            ./build/citool/debug/citool postprocess-metrics obj/build/metrics.json ${GITHUB_STEP_SUMMARY}
+          else
+            echo "No metrics.json found"
+          fi
+
       - name: upload job metrics to DataDog
         if: needs.calculate_matrix.outputs.run_type != 'pr'
         env:

src/bootstrap/src/utils/metrics.rs

@@ -200,6 +200,14 @@ impl BuildMetrics {
             }
         };
         invocations.push(JsonInvocation {
+            // The command-line invocation with which bootstrap was invoked.
+            // Skip the first argument, as it is a potentially long absolute
+            // path that is not interesting.
+            cmdline: std::env::args_os()
+                .skip(1)
+                .map(|arg| arg.to_string_lossy().to_string())
+                .collect::<Vec<_>>()
+                .join(" "),
             start_time: state
                 .invocation_start
                 .duration_since(SystemTime::UNIX_EPOCH)

src/build_helper/src/metrics.rs

@@ -1,3 +1,5 @@
+use std::time::Duration;
+
 use serde_derive::{Deserialize, Serialize};
 
 #[derive(Serialize, Deserialize)]
@@ -12,6 +14,8 @@ pub struct JsonRoot {
 #[derive(Serialize, Deserialize)]
 #[serde(rename_all = "snake_case")]
 pub struct JsonInvocation {
+    // Remembers the command-line invocation with which bootstrap was invoked.
+    pub cmdline: String,
     // Unix timestamp in seconds
     //
     // This is necessary to easily correlate this invocation with logs or other data.
@@ -98,3 +102,87 @@ fn null_as_f64_nan<'de, D: serde::Deserializer<'de>>(d: D) -> Result<f64, D::Err
     use serde::Deserialize as _;
     Option::<f64>::deserialize(d).map(|f| f.unwrap_or(f64::NAN))
 }
+
+/// Represents a single bootstrap step, with the accumulated duration of all its children.
+#[derive(Clone, Debug)]
+pub struct BuildStep {
+    pub r#type: String,
+    pub children: Vec<BuildStep>,
+    pub duration: Duration,
+}
+
+impl BuildStep {
+    /// Create a `BuildStep` representing a single invocation of bootstrap.
+    /// The most important thing is that the build step aggregates the
+    /// durations of all children, so that it can be easily accessed.
+    pub fn from_invocation(invocation: &JsonInvocation) -> Self {
+        fn parse(node: &JsonNode) -> Option<BuildStep> {
+            match node {
+                JsonNode::RustbuildStep {
+                    type_: kind,
+                    children,
+                    duration_excluding_children_sec,
+                    ..
+                } => {
+                    let children: Vec<_> = children.into_iter().filter_map(parse).collect();
+                    let children_duration = children.iter().map(|c| c.duration).sum::<Duration>();
+                    Some(BuildStep {
+                        r#type: kind.to_string(),
+                        children,
+                        duration: children_duration
+                            + Duration::from_secs_f64(*duration_excluding_children_sec),
+                    })
+                }
+                JsonNode::TestSuite(_) => None,
+            }
+        }
+
+        let duration = Duration::from_secs_f64(invocation.duration_including_children_sec);
+        let children: Vec<_> = invocation.children.iter().filter_map(parse).collect();
+        Self { r#type: "total".to_string(), children, duration }
+    }
+
+    pub fn find_all_by_type(&self, r#type: &str) -> Vec<&Self> {
+        let mut result = Vec::new();
+        self.find_by_type(r#type, &mut result);
+        result
+    }
+
+    fn find_by_type<'a>(&'a self, r#type: &str, result: &mut Vec<&'a Self>) {
+        if self.r#type == r#type {
+            result.push(self);
+        }
+        for child in &self.children {
+            child.find_by_type(r#type, result);
+        }
+    }
+}
+
+/// Writes build steps into a nice indented table.
+pub fn format_build_steps(root: &BuildStep) -> String {
+    use std::fmt::Write;
+
+    let mut substeps: Vec<(u32, &BuildStep)> = Vec::new();
+
+    fn visit<'a>(step: &'a BuildStep, level: u32, substeps: &mut Vec<(u32, &'a BuildStep)>) {
+        substeps.push((level, step));
+        for child in &step.children {
+            visit(child, level + 1, substeps);
+        }
+    }
+
+    visit(root, 0, &mut substeps);
+
+    let mut output = String::new();
+    for (level, step) in substeps {
+        let label = format!(
+            "{}{}",
+            ".".repeat(level as usize),
+            // Bootstrap steps can be generic and thus contain angle brackets (<...>).
+            // However, Markdown interprets these as HTML, so we need to escap ethem.
+            step.r#type.replace('<', "&lt;").replace('>', "&gt;")
+        );
+        writeln!(output, "{label:.<65}{:>8.2}s", step.duration.as_secs_f64()).unwrap();
+    }
+    output
+}

src/ci/citool/Cargo.lock

@@ -58,11 +58,20 @@ version = "1.0.95"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "34ac096ce696dc2fcabef30516bb13c0a68a11d30131d3df6f04711467681b04"
 
+[[package]]
+name = "build_helper"
+version = "0.1.0"
+dependencies = [
+ "serde",
+ "serde_derive",
+]
+
 [[package]]
 name = "citool"
 version = "0.1.0"
 dependencies = [
  "anyhow",
+ "build_helper",
  "clap",
  "insta",
  "serde",

src/ci/citool/Cargo.toml

@@ -10,6 +10,8 @@ serde = { version = "1", features = ["derive"] }
 serde_yaml = "0.9"
 serde_json = "1"
 
+build_helper = { path = "../../build_helper" }
+
 [dev-dependencies]
 insta = "1"
 

src/ci/citool/src/main.rs

@@ -1,3 +1,5 @@
+mod metrics;
+
 use std::collections::BTreeMap;
 use std::path::{Path, PathBuf};
 use std::process::Command;
@@ -6,6 +8,8 @@ use anyhow::Context;
 use clap::Parser;
 use serde_yaml::Value;
 
+use crate::metrics::postprocess_metrics;
+
 const CI_DIRECTORY: &str = concat!(env!("CARGO_MANIFEST_DIR"), "/..");
 const DOCKER_DIRECTORY: &str = concat!(env!("CARGO_MANIFEST_DIR"), "/../docker");
 const JOBS_YML_PATH: &str = concat!(env!("CARGO_MANIFEST_DIR"), "/../github-actions/jobs.yml");
@@ -338,6 +342,14 @@ enum Args {
         #[clap(long = "type", default_value = "auto")]
         job_type: JobType,
     },
+    /// Postprocess the metrics.json file generated by bootstrap.
+    PostprocessMetrics {
+        /// Path to the metrics.json file
+        metrics_path: PathBuf,
+        /// Path to a file where the postprocessed metrics summary will be stored.
+        /// Usually, this will be GITHUB_STEP_SUMMARY on CI.
+        summary_path: PathBuf,
+    },
 }
 
 #[derive(clap::ValueEnum, Clone)]
@@ -369,6 +381,9 @@ fn main() -> anyhow::Result<()> {
         Args::RunJobLocally { job_type, name } => {
             run_workflow_locally(load_db(default_jobs_file)?, job_type, name)?
         }
+        Args::PostprocessMetrics { metrics_path, summary_path } => {
+            postprocess_metrics(&metrics_path, &summary_path)?;
+        }
     }
 
     Ok(())

src/ci/citool/src/metrics.rs

@@ -0,0 +1,164 @@
+use std::collections::BTreeMap;
+use std::fs::File;
+use std::io::Write;
+use std::path::Path;
+
+use anyhow::Context;
+use build_helper::metrics::{
+    BuildStep, JsonNode, JsonRoot, TestOutcome, TestSuite, TestSuiteMetadata, format_build_steps,
+};
+
+pub fn postprocess_metrics(metrics_path: &Path, summary_path: &Path) -> anyhow::Result<()> {
+    let metrics = load_metrics(metrics_path)?;
+
+    let mut file = File::options()
+        .append(true)
+        .create(true)
+        .open(summary_path)
+        .with_context(|| format!("Cannot open summary file at {summary_path:?}"))?;
+
+    if !metrics.invocations.is_empty() {
+        writeln!(file, "# Bootstrap steps")?;
+        record_bootstrap_step_durations(&metrics, &mut file)?;
+        record_test_suites(&metrics, &mut file)?;
+    }
+
+    Ok(())
+}
+
+fn record_bootstrap_step_durations(metrics: &JsonRoot, file: &mut File) -> anyhow::Result<()> {
+    for invocation in &metrics.invocations {
+        let step = BuildStep::from_invocation(invocation);
+        let table = format_build_steps(&step);
+        eprintln!("Step `{}`\n{table}\n", invocation.cmdline);
+        writeln!(
+            file,
+            r"<details>
+<summary>{}</summary>
+<pre><code>{table}</code></pre>
+</details>
+",
+            invocation.cmdline
+        )?;
+    }
+    eprintln!("Recorded {} bootstrap invocation(s)", metrics.invocations.len());
+
+    Ok(())
+}
+
+fn record_test_suites(metrics: &JsonRoot, file: &mut File) -> anyhow::Result<()> {
+    let suites = get_test_suites(&metrics);
+
+    if !suites.is_empty() {
+        let aggregated = aggregate_test_suites(&suites);
+        let table = render_table(aggregated);
+        writeln!(file, "\n# Test results\n")?;
+        writeln!(file, "{table}")?;
+    } else {
+        eprintln!("No test suites found in metrics");
+    }
+
+    Ok(())
+}
+
+fn render_table(suites: BTreeMap<String, TestSuiteRecord>) -> String {
+    use std::fmt::Write;
+
+    let mut table = "| Test suite | Passed ✅ | Ignored 🚫 | Failed  ❌ |\n".to_string();
+    writeln!(table, "|:------|------:|------:|------:|").unwrap();
+
+    fn write_row(
+        buffer: &mut String,
+        name: &str,
+        record: &TestSuiteRecord,
+        surround: &str,
+    ) -> std::fmt::Result {
+        let TestSuiteRecord { passed, ignored, failed } = record;
+        let total = (record.passed + record.ignored + record.failed) as f64;
+        let passed_pct = ((*passed as f64) / total) * 100.0;
+        let ignored_pct = ((*ignored as f64) / total) * 100.0;
+        let failed_pct = ((*failed as f64) / total) * 100.0;
+
+        write!(buffer, "| {surround}{name}{surround} |")?;
+        write!(buffer, " {surround}{passed} ({passed_pct:.0}%){surround} |")?;
+        write!(buffer, " {surround}{ignored} ({ignored_pct:.0}%){surround} |")?;
+        writeln!(buffer, " {surround}{failed} ({failed_pct:.0}%){surround} |")?;
+
+        Ok(())
+    }
+
+    let mut total = TestSuiteRecord::default();
+    for (name, record) in suites {
+        write_row(&mut table, &name, &record, "").unwrap();
+        total.passed += record.passed;
+        total.ignored += record.ignored;
+        total.failed += record.failed;
+    }
+    write_row(&mut table, "Total", &total, "**").unwrap();
+    table
+}
+
+#[derive(Default)]
+struct TestSuiteRecord {
+    passed: u64,
+    ignored: u64,
+    failed: u64,
+}
+
+fn aggregate_test_suites(suites: &[&TestSuite]) -> BTreeMap<String, TestSuiteRecord> {
+    let mut records: BTreeMap<String, TestSuiteRecord> = BTreeMap::new();
+    for suite in suites {
+        let name = match &suite.metadata {
+            TestSuiteMetadata::CargoPackage { crates, stage, .. } => {
+                format!("{} (stage {stage})", crates.join(", "))
+            }
+            TestSuiteMetadata::Compiletest { suite, stage, .. } => {
+                format!("{suite} (stage {stage})")
+            }
+        };
+        let record = records.entry(name).or_default();
+        for test in &suite.tests {
+            match test.outcome {
+                TestOutcome::Passed => {
+                    record.passed += 1;
+                }
+                TestOutcome::Failed => {
+                    record.failed += 1;
+                }
+                TestOutcome::Ignored { .. } => {
+                    record.ignored += 1;
+                }
+            }
+        }
+    }
+    records
+}
+
+fn get_test_suites(metrics: &JsonRoot) -> Vec<&TestSuite> {
+    fn visit_test_suites<'a>(nodes: &'a [JsonNode], suites: &mut Vec<&'a TestSuite>) {
+        for node in nodes {
+            match node {
+                JsonNode::RustbuildStep { children, .. } => {
+                    visit_test_suites(&children, suites);
+                }
+                JsonNode::TestSuite(suite) => {
+                    suites.push(&suite);
+                }
+            }
+        }
+    }
+
+    let mut suites = vec![];
+    for invocation in &metrics.invocations {
+        visit_test_suites(&invocation.children, &mut suites);
+    }
+    suites
+}
+
+fn load_metrics(path: &Path) -> anyhow::Result<JsonRoot> {
+    let metrics = std::fs::read_to_string(path)
+        .with_context(|| format!("Cannot read JSON metrics from {path:?}"))?;
+    let metrics: JsonRoot = serde_json::from_str(&metrics)
+        .with_context(|| format!("Cannot deserialize JSON metrics from {path:?}"))?;
+    Ok(metrics)
+}

src/tools/opt-dist/src/metrics.rs

@@ -1,33 +1,10 @@
 use std::time::Duration;
 
-use build_helper::metrics::{JsonNode, JsonRoot};
+use build_helper::metrics::{BuildStep, JsonRoot, format_build_steps};
 use camino::Utf8Path;
 
 use crate::timer::TimerSection;
 
-#[derive(Clone, Debug)]
-pub struct BuildStep {
-    r#type: String,
-    children: Vec<BuildStep>,
-    duration: Duration,
-}
-
-impl BuildStep {
-    pub fn find_all_by_type(&self, r#type: &str) -> Vec<&BuildStep> {
-        let mut result = Vec::new();
-        self.find_by_type(r#type, &mut result);
-        result
-    }
-    fn find_by_type<'a>(&'a self, r#type: &str, result: &mut Vec<&'a BuildStep>) {
-        if self.r#type == r#type {
-            result.push(self);
-        }
-        for child in &self.children {
-            child.find_by_type(r#type, result);
-        }
-    }
-}
-
 /// Loads the metrics of the most recent bootstrap execution from a metrics.json file.
 pub fn load_metrics(path: &Utf8Path) -> anyhow::Result<BuildStep> {
     let content = std::fs::read(path.as_std_path())?;
@@ -37,30 +14,7 @@ pub fn load_metrics(path: &Utf8Path) -> anyhow::Result<BuildStep> {
         .pop()
         .ok_or_else(|| anyhow::anyhow!("No bootstrap invocation found in metrics file"))?;
 
-    fn parse(node: JsonNode) -> Option<BuildStep> {
+    Ok(BuildStep::from_invocation(&invocation))
-        match node {
-            JsonNode::RustbuildStep {
-                type_: kind,
-                children,
-                duration_excluding_children_sec,
-                ..
-            } => {
-                let children: Vec<_> = children.into_iter().filter_map(parse).collect();
-                let children_duration = children.iter().map(|c| c.duration).sum::<Duration>();
-                Some(BuildStep {
-                    r#type: kind.to_string(),
-                    children,
-                    duration: children_duration
-                        + Duration::from_secs_f64(duration_excluding_children_sec),
-                })
-            }
-            JsonNode::TestSuite(_) => None,
-        }
-    }
-
-    let duration = Duration::from_secs_f64(invocation.duration_including_children_sec);
-    let children: Vec<_> = invocation.children.into_iter().filter_map(parse).collect();
-    Ok(BuildStep { r#type: "root".to_string(), children, duration })
 }
 
 /// Logs the individual metrics in a table and add Rustc and LLVM durations to the passed
@@ -82,27 +36,6 @@ pub fn record_metrics(metrics: &BuildStep, timer: &mut TimerSection) {
         timer.add_duration("Rustc", rustc_duration);
     }
 
-    log_metrics(metrics);
+    let output = format_build_steps(metrics);
-}
-
-fn log_metrics(metrics: &BuildStep) {
-    use std::fmt::Write;
-
-    let mut substeps: Vec<(u32, &BuildStep)> = Vec::new();
-
-    fn visit<'a>(step: &'a BuildStep, level: u32, substeps: &mut Vec<(u32, &'a BuildStep)>) {
-        substeps.push((level, step));
-        for child in &step.children {
-            visit(child, level + 1, substeps);
-        }
-    }
-
-    visit(metrics, 0, &mut substeps);
-
-    let mut output = String::new();
-    for (level, step) in substeps {
-        let label = format!("{}{}", ".".repeat(level as usize), step.r#type);
-        writeln!(output, "{label:<65}{:>8.2}s", step.duration.as_secs_f64()).unwrap();
-    }
     log::info!("Build step durations\n{output}");
 }