Add job duration changes stats in post-merge analysis

Author: Kobzol

src/ci/citool/src/analysis.rs

@@ -1,10 +1,11 @@
-use std::collections::{BTreeMap, HashMap, HashSet};
 use std::fmt::Debug;
 
 use build_helper::metrics::{
     BuildStep, JsonRoot, TestOutcome, TestSuite, TestSuiteMetadata, escape_step_name,
     format_build_steps,
 };
+use std::collections::{BTreeMap, HashMap, HashSet};
+use std::time::Duration;
 
 use crate::metrics;
 use crate::metrics::{JobMetrics, JobName, get_test_suites};
@@ -184,11 +185,61 @@ fn render_table(suites: BTreeMap<String, TestSuiteRecord>) -> String {
 }
 
 /// Outputs a report of test differences between the `parent` and `current` commits.
-pub fn output_test_diffs(job_metrics: HashMap<JobName, JobMetrics>) {
+pub fn output_test_diffs(job_metrics: &HashMap<JobName, JobMetrics>) {
     let aggregated_test_diffs = aggregate_test_diffs(&job_metrics);
     report_test_diffs(aggregated_test_diffs);
 }
 
+/// Prints the ten largest differences in bootstrap durations.
+pub fn output_largest_duration_changes(job_metrics: &HashMap<JobName, JobMetrics>) {
+    struct Entry<'a> {
+        job: &'a JobName,
+        before: Duration,
+        after: Duration,
+        change: f64,
+    }
+
+    let mut changes: Vec<Entry> = vec![];
+    for (job, metrics) in job_metrics {
+        if let Some(parent) = &metrics.parent {
+            let duration_before = parent
+                .invocations
+                .iter()
+                .map(|i| BuildStep::from_invocation(i).duration)
+                .sum::<Duration>();
+            let duration_after = metrics
+                .current
+                .invocations
+                .iter()
+                .map(|i| BuildStep::from_invocation(i).duration)
+                .sum::<Duration>();
+            let pct_change = duration_after.as_secs_f64() / duration_before.as_secs_f64();
+            let pct_change = pct_change * 100.0;
+            // Normalize around 100, to get + for regression and - for improvements
+            let pct_change = pct_change - 100.0;
+            changes.push(Entry {
+                job,
+                before: duration_before,
+                after: duration_after,
+                change: pct_change,
+            });
+        }
+    }
+    changes.sort_by(|e1, e2| e1.change.partial_cmp(&e2.change).unwrap().reverse());
+
+    println!("# Job duration changes");
+    for (index, entry) in changes.into_iter().take(10).enumerate() {
+        println!(
+            "{}. `{}`: {:.1}s -> {:.1}s ({:.1}%)",
+            index + 1,
+            entry.job,
+            entry.before.as_secs_f64(),
+            entry.after.as_secs_f64(),
+            entry.change
+        );
+    }
+}
+
 #[derive(Default)]
 struct TestSuiteRecord {
     passed: u64,

src/ci/citool/src/main.rs

@@ -15,7 +15,7 @@ use clap::Parser;
 use jobs::JobDatabase;
 use serde_yaml::Value;
 
-use crate::analysis::output_test_diffs;
+use crate::analysis::{output_largest_duration_changes, output_test_diffs};
 use crate::cpu_usage::load_cpu_usage;
 use crate::datadog::upload_datadog_metric;
 use crate::jobs::RunType;
@@ -160,7 +160,7 @@ fn postprocess_metrics(
                     job_name,
                     JobMetrics { parent: Some(parent_metrics), current: metrics },
                 )]);
-                output_test_diffs(job_metrics);
+                output_test_diffs(&job_metrics);
                 return Ok(());
             }
             Err(error) => {
@@ -180,7 +180,8 @@ fn post_merge_report(db: JobDatabase, current: String, parent: String) -> anyhow
     let metrics = download_auto_job_metrics(&db, &parent, &current)?;
 
     println!("\nComparing {parent} (parent) -> {current} (this PR)\n");
-    output_test_diffs(metrics);
+    output_test_diffs(&metrics);
+    output_largest_duration_changes(&metrics);
 
     Ok(())
 }