Report some more data

src/egraph.rs

@@ -429,9 +429,10 @@ impl<L: Language, M: Metadata<L>> EGraph<L, M> {
 
     /// Does very little since you're in parent-pointers mode.
     #[cfg(feature = "parent-pointers")]
-    pub fn rebuild(&mut self) {
+    pub fn rebuild(&mut self) -> usize {
         info!("Skipping rebuild because we have parent pointers");
         self.rebuild_classes();
+        0
     }
 
     /// Restores the egraph invariants of congruence and enode uniqueness.
@@ -465,10 +466,10 @@ impl<L: Language, M: Metadata<L>> EGraph<L, M> {
     /// assert_eq!(egraph.find(ax), egraph.find(ay));
     /// ```
     #[cfg(not(feature = "parent-pointers"))]
-    pub fn rebuild(&mut self) {
+    pub fn rebuild(&mut self) -> usize {
         if self.unions_since_rebuild == 0 {
             info!("Skipping rebuild!");
-            return;
+            return 0;
         }
 
         self.unions_since_rebuild = 0;
@@ -509,6 +510,8 @@ impl<L: Language, M: Metadata<L>> EGraph<L, M> {
             n_unions,
             trimmed_nodes,
         );
+
+        n_rebuilds
     }
 
     /// Unions two eclasses given their ids.

src/run.rs

@@ -246,6 +246,8 @@ pub struct Iteration<IterData> {
     pub total_time: f64,
     /// The user provided annotation for this iteration
     pub data: IterData,
+    /// The number of rebuild iterations done after this iteration completed.
+    pub n_rebuilds: usize,
 }
 
 type RunnerResult<T> = std::result::Result<T, StopReason>;
@@ -315,6 +317,28 @@ where
         self
     }
 
+    #[rustfmt::skip]
+    /// Prints some information about a runners run.
+    pub fn print_report(&self) {
+        let search_time: f64 = self.iterations.iter().map(|i| i.search_time).sum();
+        let apply_time: f64 = self.iterations.iter().map(|i| i.apply_time).sum();
+        let rebuild_time: f64 = self.iterations.iter().map(|i| i.rebuild_time).sum();
+        let total_time: f64 = self.iterations.iter().map(|i| i.total_time).sum();
+
+        let iters = self.iterations.len();
+        let rebuilds: usize = self.iterations.iter().map(|i| i.n_rebuilds).sum();
+
+        println!("Runner report");
+        println!("=============");
+        println!("  Stop reason: {:?}", self.stop_reason.as_ref().unwrap());
+        println!("  Iterations: {}", iters);
+        println!("  Rebuilds: {}, {:.2} per iter", rebuilds, (rebuilds as f64) / (iters as f64));
+        println!("  Total time: {}", total_time);
+        println!("    Search:  ({:.2}) {}", search_time / total_time, search_time);
+        println!("    Apply:   ({:.2}) {}", apply_time / total_time, apply_time);
+        println!("    Rebuild: ({:.2}) {}", rebuild_time / total_time, rebuild_time);
+    }
+
     fn run_one(&mut self, rules: &[Rewrite<L, M>]) -> RunnerResult<()> {
         assert!(self.stop_reason.is_none());
 
@@ -368,7 +392,7 @@ where
         info!("Apply time: {}", apply_time);
 
         let rebuild_time = Instant::now();
-        self.egraph.rebuild();
+        let n_rebuilds = self.egraph.rebuild();
 
         let rebuild_time = rebuild_time.elapsed().as_secs_f64();
         info!("Rebuild time: {}", rebuild_time);
@@ -387,6 +411,7 @@ where
             search_time,
             apply_time,
             rebuild_time,
+            n_rebuilds,
             data: IterData::make(&self),
             total_time: start_time.elapsed().as_secs_f64(),
         });

src/test.rs

@@ -58,13 +58,14 @@ impl<T> Reporter<T> {
     }
 
     #[cfg(not(feature = "reports"))]
-    pub fn report<R>(self, _to_report: impl FnOnce(&T) -> &R) -> T {
+    pub fn report<R>(self, to_report: impl FnOnce(&T) -> &R) -> T {
         if let Some(dir) = var::<PathBuf>("EGG_BENCH_DIR") {
             eprintln!(
                 "EGG_BENCH_DIR is set to '{:?}', but the 'reports' feature is not enabled",
                 dir
             );
         }
+        to_report(&self.result);
         self.result
     }
 
@@ -164,7 +165,6 @@ where
         let id = egraph.find(*self.roots.last().unwrap());
 
         let (cost, best) = Extractor::new(egraph, AstSize).find_best(id);
-        println!("Stop reason: {:?}", self.stop_reason.as_ref().unwrap());
         println!("End ({}): {}", cost, best.pretty(80));
 
         for (i, goal) in goals.iter().enumerate() {
@@ -223,8 +223,8 @@ macro_rules! test_fn {
 
             let runner = $crate::test::run(name, || {
                 $runner.with_expr(&start).run(&rules)
-            })
-            .report(|r| &r.iterations);
+            }).report(|r| &r.iterations);
+            runner.print_report();
 
             let goals = &[$(
                 $goal.parse().unwrap()