1 files changed, 12 insertions, 3 deletions

diff --git a/src/state.rs b/src/state.rs
index 152d569..d70af11 100644
--- a/src/state.rs
+++ b/src/state.rs
@@ -1,8 +1,9 @@
 use crate::data::{Data, DataError};
 use crate::result::{Measurement, OpMeasurements, Operation};
 use crate::step::Step;
+use log::{debug, info};
+use std::path::Path;
 use std::time::Instant;
-use std::path::{Path};
 use tempfile::{tempdir, TempDir};
 
 /// Runtime state for running Obnam benchmarks.
@@ -44,25 +45,31 @@ impl State {
     }
 
     pub fn execute(&mut self, step: &Step) -> Result<Option<OpMeasurements>, StateError> {
+        debug!("executing step {:?}", step);
         let now = Instant::now();
         let om = match step {
             Step::Start(name) => {
+                info!("starting benchmark {}", name);
                 self.current_benchmark = Some(CurrentBenchmark::new(name, self.tempdir.path())?);
                 None
             }
-            Step::Stop(_) => {
+            Step::Stop(name) => {
+                info!("ending benchmark {}", name);
                 self.current_benchmark = None;
                 None
             }
             Step::Create(x) => {
+                info!("creating {} test data files", x.files);
                 self.current()?.data.create(x)?;
                 None
             }
             Step::Rename(x) => {
+                info!("renaming {} test data files", x.files);
                 self.current()?.data.rename(x)?;
                 None
             }
             Step::Delete(x) => {
+                info!("deleting {} test data files", x.files);
                 self.current()?.data.delete(x)?;
                 None
             }
@@ -70,12 +77,12 @@ impl State {
             Step::Restore(x) => Some(restore(*x, self.current()?)?),
         };
 
-        println!("{:?}", step);
         let t = std::time::Duration::from_millis(10);
         std::thread::sleep(t);
 
         if let Some(mut om) = om {
             let ms = now.elapsed().as_millis();
+            debug!("step duration was {} ms", ms);
             om.push(Measurement::DurationMs(ms));
             Ok(Some(om))
         } else {
@@ -85,6 +92,7 @@ impl State {
 }
 
 fn backup(i: usize, current: &CurrentBenchmark) -> Result<OpMeasurements, StateError> {
+    info!("backing up generation number {}", i);
     let mut om = OpMeasurements::new(&current.name, Operation::Backup(i));
     om.push(Measurement::TotalFiles(current.data.file_count()?));
     om.push(Measurement::TotalData(current.data.file_size()?));
@@ -92,6 +100,7 @@ fn backup(i: usize, current: &CurrentBenchmark) -> Result<OpMeasurements, StateE
 }
 
 fn restore(i: usize, current: &CurrentBenchmark) -> Result<OpMeasurements, StateError> {
+    info!("restoring generation number {}", i);
     Ok(OpMeasurements::new(&current.name, Operation::Restore(i)))
 }