Switch to slog

Cargo.toml

@@ -12,6 +12,9 @@ futures-util = "0.3"
 async-trait = "0.1"
 tokio = { version = "1.6.1", features = ["rt", "process", "io-util", "macros", "sync"] }
 once_cell = "1.4"
+slog = { version = "2", features = ["max_level_trace", "release_max_level_trace"] }
+slog-term = "2.5"
+slog-async = "2.7"
 
 [dev-dependencies]
 tempfile = "3"

src/setup/core.rs

@@ -3,20 +3,21 @@ use super::setup::Setup;
 use super::util::{AddableResource, InternalAddResult};
 use super::SymbolRunner;
 use crate::async_utils::join;
-use crate::loggers::{Logger, StoringLogger};
 use crate::resources::{FromArtifact, FromResource};
 use crate::symbols::Symbol;
 use crate::to_artifact::ToArtifact;
 use crate::{ImplementationBuilder, ResourceLocator};
 use async_trait::async_trait;
+use slog::{debug, o, trace, Logger};
 use std::error::Error;
 use std::fmt::Debug;
 use std::hash::Hash;
 use std::marker::PhantomData;
+use std::rc::Rc;
 
 #[async_trait(?Send)]
 pub trait AddGeneric<X: ToArtifact> {
-  async fn add_generic(&self, x: X) -> InternalAddResult<X>;
+  async fn add_generic(&self, logger: &Rc<Logger>, x: X) -> InternalAddResult<X>;
 }
 
 macro_rules! add_generic {
@@ -25,9 +26,9 @@ macro_rules! add_generic {
     #[async_trait(?Send)]
     impl<SR, L, B, Rs, As> AddGeneric<()> for Setup<SR, L, B, Rs, As>
     {
-      async fn add_generic(&self, (): ()) -> Result<(StoringLogger, (), bool), (StoringLogger, Box<dyn Error>)>
+      async fn add_generic(&self, _: &Rc<Logger>, (): ()) -> Result<((), bool), Box<dyn Error>>
       {
-        Ok((StoringLogger::default(), (), false))
+        Ok(((), false))
       }
     }
   );
@@ -45,18 +46,16 @@ macro_rules! add_generic {
       ),*
     {
       #[allow(unused, clippy::shadow_unrelated)]
-      async fn add_generic(&self, ($($name,)*): ($($name,)*)) -> Result<(StoringLogger, ($($name::Artifact,)*), bool), (StoringLogger, Box<dyn Error>)>
+      async fn add_generic(&self, logger: &Rc<Logger>, ($($name,)*): ($($name,)*)) -> Result<(($($name::Artifact,)*), bool), Box<dyn Error>>
       {
-        let ($($name,)*) = join!($(self.add($name, false),)*);
-        let logger = StoringLogger::default();
+        let ($($name,)*) = join!($(self.add(logger, $name, false),)*);
         let mut did_run_any = false;
         $(
-        let (log, artifact, did_run) = $name?;
-        logger.put(log.release());
+        let (artifact, did_run) = $name?;
         did_run_any = did_run_any || did_run;
         let $name = artifact;
         )*
-        Ok((logger, ($($name,)*), did_run_any))
+        Ok((($($name,)*), did_run_any))
       }
     }
   );
@@ -80,13 +79,13 @@ where
   Self: AddGeneric<B::Prerequisites>,
   T::Artifact: Clone,
 {
-  async fn add_generic(&self, r: Option<T>) -> InternalAddResult<Option<T>> {
+  async fn add_generic(&self, logger: &Rc<Logger>, r: Option<T>) -> InternalAddResult<Option<T>> {
     Ok(match r {
       Some(r) => {
-        let (logger, result, did_run) = self.add(r, false).await?;
-        (logger, Some(result), did_run)
+        let (result, did_run) = self.add(logger, r, false).await?;
+        (Some(result), did_run)
       }
-      None => (StoringLogger::default(), None, false),
+      None => (None, false),
     })
   }
 }
@@ -104,8 +103,8 @@ where
   T::Artifact: Clone,
   RegularSetupCore<SR, L, B>: 'static + SetupCore<T, Self>,
 {
-  async fn add_generic(&self, r: T) -> InternalAddResult<T> {
-    self.add(r, false).await
+  async fn add_generic(&self, logger: &Rc<Logger>, r: T) -> InternalAddResult<T> {
+    self.add(logger, r, false).await
   }
 }
 
@@ -114,6 +113,7 @@ pub trait SetupCore<R: AddableResource, S> {
   async fn add<RR: AsRef<R>>(
     &self,
     setup: &S,
+    logger: &Rc<Logger>,
     resource: RR,
     force_run: bool,
   ) -> InternalAddResult<R>;
@@ -145,71 +145,66 @@ where
   async fn add<RR: AsRef<R>>(
     &self,
     setup: &S,
+    logger: &Rc<Logger>,
     resource: RR,
     force_run: bool,
   ) -> InternalAddResult<R> {
     let resource = resource.as_ref();
-    let logger = StoringLogger::new();
-    logger.write(4, format!("Adding {:?} ... ", resource));
-    logger.write(4, format!("(force_run is {})", force_run));
+    debug!(logger, "Adding {:?} ... ", resource);
+    debug!(logger, "(force_run is {})", force_run);
     let (location, location_prereqs) = L::locate(resource);
-    logger.trace(format!("Adding location prereqs for {:?}", resource));
-    let result = setup.add_generic(location_prereqs).await;
-    if let Err((log, e)) = result {
-      logger.put(log.release());
-      return Err((logger, e));
-    }
-    let (location_prereq_logger, _, location_prereqs_did_run) = result.unwrap();
-    logger.put(location_prereq_logger.release());
-    logger.trace(format!(
+    trace!(logger, "Adding location prereqs for {:?}", resource);
+    let location_prereq_logger = Rc::new(logger.new(o!("prereq" => "location")));
+    let (_, location_prereqs_did_run) = setup
+      .add_generic(&location_prereq_logger, location_prereqs)
+      .await?;
+    trace!(
+      logger,
       "Location prereqs for {:?} did_run: {}",
-      resource, location_prereqs_did_run
-    ));
-    logger.trace(format!("Adding implementation prereqs for {:?}", resource));
-    let result = setup.add_generic(B::prerequisites(resource)).await;
-    if let Err((log, e)) = result {
-      logger.put(log.release());
-      return Err((logger, e));
-    }
-    let (impl_prereq_logger, prereqs, prereqs_did_run) = result.unwrap();
-    logger.put(impl_prereq_logger.release());
-    logger.trace(format!(
+      resource,
+      location_prereqs_did_run
+    );
+    trace!(logger, "Adding implementation prereqs for {:?}", resource);
+    let impl_prereq_logger = Rc::new(logger.new(o!("prereq" => "implementation")));
+    let (prereqs, prereqs_did_run) = setup
+      .add_generic(&impl_prereq_logger, B::prerequisites(resource))
+      .await?;
+    trace!(
+      logger,
       "Implementation prereqs for {:?} did_run: {}",
-      resource, prereqs_did_run
-    ));
-    logger.trace(format!("Running implementation for {:?}", resource));
+      resource,
+      prereqs_did_run
+    );
+    trace!(logger, "Running implementation for {:?}", resource);
     let implementation = B::create(resource, &location, prereqs);
     let did_run_result = implementation
       .run(
         &self.symbol_runner,
-        &logger,
+        logger,
         force_run || location_prereqs_did_run || prereqs_did_run,
       )
       .await;
     match did_run_result {
       Ok(did_run) => {
-        logger.write(4, "done.");
-        Ok((logger, location, did_run))
+        debug!(logger, "done.");
+        Ok((location, did_run))
       }
-      Err(e) => Err((logger, e)),
+      Err(e) => Err(e),
     }
   }
 }
 
 #[async_trait(?Send)]
 impl<SR: SymbolRunner, L, B> SymbolRunner for RegularSetupCore<SR, L, B> {
-  async fn run_symbol<S: Symbol + Debug, LOG: Logger>(
+  async fn run_symbol<S: Symbol + Debug>(
     &self,
     symbol: &S,
-    parent_logger: &LOG,
+    logger: &Logger,
     force: bool,
   ) -> Result<bool, Box<dyn Error>> {
-    let logger = StoringLogger::new();
-    logger.write(4, format!("Directly running {:?} ...", symbol));
-    let result = self.symbol_runner.run_symbol(symbol, &logger, force).await;
-    logger.write(4, "done.");
-    let max_level = if result.is_err() { 5 } else { 3 };
-    parent_logger.put(logger.release().into_iter().filter(|e| e.0 <= max_level));
+    debug!(logger, "Directly running {:?} ...", symbol);
+    let result = self.symbol_runner.run_symbol(symbol, logger, force).await;
+    debug!(logger, "done.");
     result
   }
 }
@@ -220,12 +215,16 @@ mod test {
   use super::AddGeneric;
   use crate::async_utils::run;
   use crate::DrySymbolRunner;
+  use std::rc::Rc;
 
   #[test]
   fn empty() {
     let setup: Setup<_, (), (), (), ()> = Setup::new(DrySymbolRunner);
     run(async {
-      assert!(setup.add_generic(()).await.is_ok());
+      assert!(setup
+        .add_generic(&Rc::new(slog::Logger::root(slog::Discard, slog::o!())), ())
+        .await
+        .is_ok());
     })
   }
 }

src/setup/runnable.rs

@@ -1,16 +1,17 @@
 use super::SymbolRunner;
-use crate::loggers::Logger;
 use crate::symbols::Symbol;
 use async_trait::async_trait;
+use slog::Logger;
 use std::error::Error;
 use std::fmt::Debug;
 
+// A generalization over symbols and tuples of symbols
 #[async_trait(?Send)]
 pub trait Runnable {
-  async fn run<R: SymbolRunner, L: Logger>(
+  async fn run<R: SymbolRunner>(
     &self,
     runner: &R,
-    logger: &L,
+    logger: &Logger,
     force: bool,
   ) -> Result<bool, Box<dyn Error>>;
 }
@@ -21,10 +22,10 @@ impl<S> Runnable for S
 where
   Self: Symbol + Debug,
 {
-  async fn run<R: SymbolRunner, L: Logger>(
+  async fn run<R: SymbolRunner>(
     &self,
     runner: &R,
-    logger: &L,
+    logger: &Logger,
     force: bool,
   ) -> Result<bool, Box<dyn Error>> {
     runner.run_symbol(self, logger, force).await
@@ -38,7 +39,7 @@ macro_rules! runnable_for_tuple {
     #[allow(non_snake_case)]
     impl<$($name: Symbol + Debug,)*> Runnable for ($($name,)*) {
       #[allow(unused)]
-      async fn run<_R: SymbolRunner, _L: Logger>(&self, runner: &_R, logger: &_L, force: bool) -> Result<bool, Box<dyn Error>> {
+      async fn run<_R: SymbolRunner>(&self, runner: &_R, logger: &Logger, force: bool) -> Result<bool, Box<dyn Error>> {
         let ($($name,)*) = self;
         let mut result = false;
         $(result = runner.run_symbol($name, logger, force || result).await? || result;)*
@@ -54,10 +55,10 @@ for_each_tuple!(runnable_for_tuple);
 mod test {
   use super::Runnable;
   use crate::async_utils::run;
-  use crate::loggers::{Logger, StoringLogger};
   use crate::symbols::Symbol;
   use crate::SymbolRunner;
   use async_trait::async_trait;
+  use slog::{o, Discard, Logger};
   use std::cell::RefCell;
   use std::error::Error;
   use std::fmt::Debug;
@@ -116,10 +117,10 @@ mod test {
 
   #[async_trait(?Send)]
   impl SymbolRunner for TestSymbolRunner {
-    async fn run_symbol<S: Symbol + Debug, L: Logger>(
+    async fn run_symbol<S: Symbol + Debug>(
       &self,
       symbol: &S,
-      _logger: &L,
+      _logger: &Logger,
       force: bool,
     ) -> Result<bool, Box<dyn Error>> {
       let run = force || !symbol.target_reached().await?;
@@ -135,7 +136,7 @@ mod test {
     force: bool,
   ) -> (Rc<RefCell<usize>>, Result<bool, Box<dyn Error>>) {
     let (count, runner) = get_runner();
-    let res = run(runnable.run(&runner, &StoringLogger::new(), force));
+    let res = run(runnable.run(&runner, &Logger::root(Discard, o!()), force));
     (count, res)
   }
 

src/setup/setup.rs

@@ -1,15 +1,17 @@
 use super::core::{RegularSetupCore, SetupCore};
-use super::runnable::Runnable;
-use super::util::{AddResult, AddableResource, InternalAddResult};
+use super::util::{AddResult, AddableResource, InternalAddResult, Recorder};
 use super::SymbolRunner;
 use crate::async_utils::sleep;
-use crate::loggers::{Logger, StoringLogger};
+use crate::loggers::Logger;
 use crate::resources::{DefaultArtifacts, DefaultResources, FromArtifact, FromResource};
+use crate::symbols::Symbol;
 use crate::{DefaultBuilder, DefaultLocator};
 use futures_util::future::{FutureExt, Shared};
+use slog::{o, trace, Logger as SlogLogger};
 use std::cell::{RefCell, RefMut};
 use std::collections::HashMap;
 use std::error::Error;
+use std::fmt::Debug;
 use std::future::Future;
 use std::hash::Hash;
 use std::pin::Pin;
@@ -44,7 +46,12 @@ impl<L: 'static, B: 'static, SR: 'static, Rs: Hash + Eq + 'static, As: 'static>
 
   // FIXME: https://github.com/rust-lang/rust-clippy/issues/6353
   #[allow(clippy::await_holding_refcell_ref)]
-  pub async fn add<R: AddableResource>(&self, resource: R, force_run: bool) -> InternalAddResult<R>
+  pub async fn add<R: AddableResource>(
+    &self,
+    logger: &Rc<SlogLogger>,
+    resource: R,
+    force_run: bool,
+  ) -> InternalAddResult<R>
   where
     Rs: FromResource<R>,
     As: FromArtifact<R> + Clone,
@@ -60,24 +67,22 @@ impl<L: 'static, B: 'static, SR: 'static, Rs: Hash + Eq + 'static, As: 'static>
       );
       resources.insert(storable_resource, future.clone());
       drop(resources);
-      let logger = StoringLogger::default();
-      logger.trace(format!(
-        "{:?} already added",
-        weak_resource.upgrade().expect("Dangling!")
-      ));
+      trace!(logger, "Resource already added");
       let (t, did_run) = future.await;
-      Ok((logger, t, did_run))
+      Ok((t, did_run))
     } else {
       let inner_weak = Rc::downgrade(&self.0);
+      let logger_weak = Rc::downgrade(logger);
       let future = Box::pin(async move {
         let this = Self(inner_weak.upgrade().expect("Dangling!"));
+        let logger = logger_weak.upgrade().expect("Dangling!");
         let resource = weak_resource.upgrade().expect("Dangling!");
         // Need to convert Box<Error> to String for Clone for Shared
-        let result = this.0.core.add(&this, resource, force_run).await;
+        let result = this.0.core.add(&this, &logger, resource, force_run).await;
 
         result
-          .map(|(logger, t, did_run)| (logger, As::from_artifact(t), did_run))
-          .map_err(|(logger, e)| (logger, e.to_string()))
+          .map(|(t, did_run)| (As::from_artifact(t), did_run))
+          .map_err(|e| e.to_string())
       })
       .shared();
       let future_clone = future.clone();
@@ -89,15 +94,15 @@ impl<L: 'static, B: 'static, SR: 'static, Rs: Hash + Eq + 'static, As: 'static>
             // Step back to give the initial caller time to handle the error before unwrapping
             sleep(Duration::from_millis(0)).await;
           }
-          result.map(|(_, t, did_run)| (t, did_run)).unwrap()
+          result.unwrap()
         }) as Pin<Box<dyn Future<Output = (As, bool)>>>)
           .shared(),
       );
       drop(resources);
       let result = future.await;
-      result.map_err(|(logger, e)| (logger, e.into()))
+      result.map_err(|e| e.into())
     };
-    result.map(|(logger, t, did_run)| (logger, t.into_artifact(), did_run))
+    result.map(|(t, did_run)| (t.into_artifact(), did_run))
   }
 }
 
@@ -139,23 +144,28 @@ impl<
     R::Artifact: Clone,
     RegularSetupCore<SR, L, B>: SetupCore<R, Setup<SR, L, B, Rs, As>>,
   {
-    let result = self.1.add(resource, force_run).await;
-    match result {
-      Ok((logger, t, did_run)) => {
-        if self
-          .0
-          .put(logger.release().into_iter().filter(|e| e.0 <= 3))
-          == 0
-        {
-          self.0.write(3, ".");
+    let recorder = Recorder::default();
+    let drain = recorder.clone();
+    let log = Rc::new(slog::Logger::root(
+      drain,
+      o!("resource" => format!("{:?}", resource)),
+    ));
+
+    let result = self.1.add(&log, resource, force_run).await;
+    match &result {
+      Ok((_, did_run)) => {
+        if *did_run {
+          let log = recorder.to_string(slog::Level::Info);
+          if !log.is_empty() {
+            self.0.writeln(3, log);
+            return result;
           }
-        Ok((t, did_run))
         }
-      Err((logger, e)) => {
-        self.0.put(logger.release());
-        Err(e)
+        self.0.write(3, ".");
       }
+      Err(_) => self.0.writeln(2, recorder.to_string(slog::Level::Trace)),
     }
+    result
   }
   pub async fn add<R: AddableResource>(&self, resource: R) -> AddResult<R>
   where
@@ -168,7 +178,7 @@ impl<
     self.add_force(resource, false).await
   }
 
-  pub async fn run_symbol<S: Runnable>(
+  pub async fn run_symbol<S: Symbol + Debug>(
     &self,
     symbol: S,
     force: bool,
@@ -176,7 +186,23 @@ impl<
   where
     RegularSetupCore<SR, L, B>: SymbolRunner,
   {
-    symbol.run(&(self.1).0.core, &self.0, force).await
+    let recorder = Recorder::default();
+    let drain = recorder.clone();
+    let log = Rc::new(slog::Logger::root(
+      drain,
+      o!("symbol" => format!("{:?}", symbol)),
+    ));
+
+    let result = (self.1).0.core.run_symbol(&symbol, &log, force).await;
+    self.0.write(
+      3,
+      recorder.to_string(if result.is_ok() {
+        slog::Level::Info
+      } else {
+        slog::Level::Trace
+      }),
+    );
+    result
   }
 }
 
@@ -184,12 +210,13 @@ impl<
 mod test {
   use super::SymbolRunner;
   use crate::async_utils::run;
-  use crate::loggers::{Logger, StoringLogger};
+  use crate::loggers::StoringLogger;
   use crate::resources::{FromArtifact, FromResource, Resource};
   use crate::symbols::Symbol;
   use crate::to_artifact::ToArtifact;
   use crate::{ImplementationBuilder, ResourceLocator, Setup};
   use async_trait::async_trait;
+  use slog::Logger;
   use std::cell::RefCell;
   use std::error::Error;
   use std::fmt::Debug;
@@ -201,10 +228,10 @@ mod test {
 
   #[async_trait(?Send)]
   impl SymbolRunner for TestSymbolRunner {
-    async fn run_symbol<S: Symbol + Debug, L: Logger>(
+    async fn run_symbol<S: Symbol + Debug>(
       &self,
       symbol: &S,
-      _logger: &L,
+      _logger: &Logger,
       force: bool,
     ) -> Result<bool, Box<dyn Error>> {
       let run = force || !symbol.target_reached().await?;

src/setup/symbol_runner.rs

@@ -1,7 +1,8 @@
 use crate::async_utils::sleep;
-use crate::loggers::Logger;
 use crate::symbols::Symbol;
 use async_trait::async_trait;
+use slog::Logger;
+use slog::{debug, info, trace};
 use std::error::Error;
 use std::fmt;
 use std::fmt::Debug;
@@ -9,10 +10,10 @@ use std::time::Duration;
 
 #[async_trait(?Send)]
 pub trait SymbolRunner {
-  async fn run_symbol<S: Symbol + Debug, L: Logger>(
+  async fn run_symbol<S: Symbol + Debug>(
     &self,
     symbol: &S,
-    logger: &L,
+    logger: &Logger,
     force: bool,
   ) -> Result<bool, Box<dyn Error>>;
 }
@@ -37,18 +38,19 @@ impl InitializingSymbolRunner {
     Self
   }
 
-  async fn exec_symbol<S: Symbol + Debug, L: Logger>(
+  async fn exec_symbol<S: Symbol + Debug>(
     &self,
     symbol: &S,
-    logger: &L,
+    logger: &Logger,
   ) -> Result<(), Box<dyn Error>> {
-    logger.info(format!("Executing {:?}", symbol));
+    info!(logger, "Executing {:?}", symbol);
     symbol.execute().await?;
     let target_reached = symbol.target_reached().await?;
-    logger.trace(format!(
+    trace!(
+      logger,
       "Symbol reports target_reached: {:?} (should be true)",
       target_reached
-    ));
+    );
     if target_reached {
       Ok(())
     } else {
@@ -59,25 +61,26 @@ impl InitializingSymbolRunner {
 
 #[async_trait(?Send)]
 impl SymbolRunner for InitializingSymbolRunner {
-  async fn run_symbol<S: Symbol + Debug, L: Logger>(
+  async fn run_symbol<S: Symbol + Debug>(
     &self,
     symbol: &S,
-    logger: &L,
+    logger: &Logger,
     force: bool,
   ) -> Result<bool, Box<dyn Error>> {
     let executed = if force {
-      logger.debug("Forcing symbol execution");
+      debug!(logger, "Forcing symbol execution");
       self.exec_symbol(symbol, logger).await?;
       true
     } else {
       let target_reached = symbol.target_reached().await?;
       if target_reached {
-        logger.debug(format!("{:?} already reached", symbol));
+        debug!(logger, "{:?} already reached", symbol);
       } else {
-        logger.trace(format!(
+        trace!(
+          logger,
           "Symbol reports target_reached: {:?}",
           target_reached
-        ));
+        );
         self.exec_symbol(symbol, logger).await?;
       }
       !target_reached
@@ -106,10 +109,10 @@ where
     clippy::cast_possible_truncation,
     clippy::cast_precision_loss
   )]
-  async fn run_symbol<S: Symbol + Debug, L: Logger>(
+  async fn run_symbol<S: Symbol + Debug>(
     &self,
     symbol: &S,
-    logger: &L,
+    logger: &Logger,
     force: bool,
   ) -> Result<bool, Box<dyn Error>> {
     sleep(Duration::from_millis(
@@ -139,23 +142,23 @@ impl DrySymbolRunner {
 
 #[async_trait(?Send)]
 impl SymbolRunner for DrySymbolRunner {
-  async fn run_symbol<S: Symbol + Debug, L: Logger>(
+  async fn run_symbol<S: Symbol + Debug>(
     &self,
     symbol: &S,
-    logger: &L,
+    logger: &Logger,
     force: bool,
   ) -> Result<bool, Box<dyn Error>> {
     let would_execute = if force {
-      logger.info(format!("Would force-execute {:?}", symbol));
+      info!(logger, "Would force-execute {:?}", symbol);
       true
     } else {
       let target_reached = symbol.target_reached().await?;
-      logger.debug(format!(
-        "Symbol reports target_reached: {:?}",
-        target_reached
-      ));
+      debug!(
+        logger,
+        "Symbol reports target_reached: {:?}", target_reached
+      );
       if !target_reached {
-        logger.info(format!("Would execute {:?}", symbol));
+        info!(logger, "Would execute {:?}", symbol);
       }
       !target_reached
     };
@@ -178,18 +181,18 @@ impl<R> SymbolRunner for ReportingSymbolRunner<R>
 where
   R: SymbolRunner,
 {
-  async fn run_symbol<S: Symbol + Debug, L: Logger>(
+  async fn run_symbol<S: Symbol + Debug>(
     &self,
     symbol: &S,
-    logger: &L,
+    logger: &Logger,
     force: bool,
   ) -> Result<bool, Box<dyn Error>> {
-    logger.debug(format!("Running symbol {:?}", symbol));
+    debug!(logger, "Running symbol {:?}", symbol);
     let res = self.0.run_symbol(symbol, logger, force).await;
     if let Err(ref e) = res {
-      logger.info(format!("Failed on {:?} with {}, aborting.", symbol, e));
+      info!(logger, "Failed on {:?} with {}, aborting.", symbol, e);
     } else {
-      logger.debug(format!("Successfully finished {:?}", symbol));
+      debug!(logger, "Successfully finished {:?}", symbol);
     }
     res
   }
@@ -200,9 +203,9 @@ mod test {
   use super::{DrySymbolRunner, InitializingSymbolRunner, ReportingSymbolRunner, SymbolRunner};
   use crate::async_utils::sleep;
   use crate::async_utils::{run, try_join};
-  use crate::loggers::StoringLogger;
   use crate::symbols::Symbol;
   use async_trait::async_trait;
+  use slog::{o, Discard, Logger};
   use std::cell::RefCell;
   use std::error::Error;
   use std::fmt;
@@ -263,7 +266,7 @@ mod test {
   }
 
   fn run_symbol<S: Symbol + Debug>(s: S) -> Result<bool, Box<dyn Error>> {
-    run(InitializingSymbolRunner::new().run_symbol(&s, &StoringLogger::new(), false))
+    run(InitializingSymbolRunner::new().run_symbol(&s, &Logger::root(Discard, o!()), false))
   }
 
   #[test]
@@ -316,8 +319,8 @@ mod test {
       let s1 = SleeperSymbol;
       let s2 = DummySymbol::new(vec![Ok(false), Ok(true)], vec![Ok(())]);
 
-      let l1 = StoringLogger::new();
-      let l2 = StoringLogger::new();
+      let l1 = Logger::root(Discard, o!());
+      let l2 = Logger::root(Discard, o!());
       let runner1 = InitializingSymbolRunner::new();
       let result = try_join!(
         runner1.run_symbol(&s1, &l1, false),
@@ -327,8 +330,6 @@ mod test {
       assert_eq!(result, (false, true));
 
       let s2 = DummySymbol::new(vec![Ok(false), Ok(true)], vec![Ok(())]);
-      let l1 = StoringLogger::new();
-      let l2 = StoringLogger::new();
       let runner2 = DrySymbolRunner::new();
       let result = try_join!(
         runner2.run_symbol(&s1, &l1, false),
@@ -338,8 +339,6 @@ mod test {
       assert_eq!(result, (false, true));
 
       let s2 = DummySymbol::new(vec![Ok(false), Ok(true)], vec![Ok(())]);
-      let l1 = StoringLogger::new();
-      let l2 = StoringLogger::new();
       let runner3 = ReportingSymbolRunner::new(runner1);
       let result = try_join!(
         runner3.run_symbol(&s1, &l1, false),

src/setup/util.rs

@@ -1,12 +1,85 @@
-use crate::loggers::StoringLogger;
 use crate::resources::Resource;
 use crate::to_artifact::ToArtifact;
+use slog::Drain;
+use slog::{OwnedKVList, Record};
+use slog_async::AsyncRecord;
+use std::cell::RefCell;
 use std::error::Error;
 use std::fmt::Debug;
+use std::io::{self, Write};
+use std::rc::Rc;
+use std::sync::{Arc, Mutex};
 
 pub trait AddableResource: 'static + Resource + Debug {}
 impl<R> AddableResource for R where R: 'static + Resource + Debug {}
 
 pub type AddResult<R> = Result<(<R as ToArtifact>::Artifact, bool), Box<dyn Error>>;
-pub type InternalAddResult<R> =
-  Result<(StoringLogger, <R as ToArtifact>::Artifact, bool), (StoringLogger, Box<dyn Error>)>;
+pub type InternalAddResult<R> = Result<(<R as ToArtifact>::Artifact, bool), Box<dyn Error>>;
+
+// From https://users.rust-lang.org/t/how-to-send-a-writer-into-a-thread/4965/10
+#[derive(Clone)]
+struct Output<W>(Rc<RefCell<W>>);
+
+impl<W: Write> Output<W> {
+  pub fn new(w: W) -> Self {
+    Self(Rc::new(RefCell::new(w)))
+  }
+}
+
+impl<W: Write> Write for Output<W> {
+  fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
+    self.0.borrow_mut().write(buf)
+  }
+
+  fn flush(&mut self) -> io::Result<()> {
+    self.0.borrow_mut().flush()
+  }
+}
+
+#[derive(Clone, Default)]
+pub struct Recorder(Arc<Mutex<Vec<AsyncRecord>>>);
+
+impl Drain for Recorder {
+  type Ok = ();
+  type Err = slog::Never;
+
+  fn log(&self, record: &Record<'_>, logger_values: &OwnedKVList) -> Result<Self::Ok, Self::Err> {
+    self
+      .0
+      .lock()
+      .unwrap()
+      .push(AsyncRecord::from(record, logger_values));
+    Ok(())
+  }
+}
+
+impl Recorder {
+  pub fn to_string(&self, filter_level: slog::Level) -> String {
+    let output = Output::new(vec![]);
+    {
+      let decorator = slog_term::PlainDecorator::new(output.clone());
+      let drain = slog_term::CompactFormat::new(decorator).build();
+      for record in &*self.0.lock().unwrap() {
+        record.as_record_values(|record, kv| {
+          if record.level() <= filter_level {
+            drain.log(record, kv).unwrap();
+          }
+        });
+      }
+    }
+    String::from_utf8(Rc::try_unwrap(output.0).unwrap().into_inner())
+      .expect("Record output should be valid UTF-8")
+  }
+}
+
+#[cfg(test)]
+mod test {
+  use super::Recorder;
+  use slog::Level;
+
+  #[test]
+  fn records_no_output() {
+    let recorder = Recorder::default();
+    assert_eq!(recorder.to_string(Level::Trace), "");
+  }
+}

tests/setup.rs

@@ -1,10 +1,11 @@
 use async_trait::async_trait;
 use schematics::async_utils::{run, sleep};
-use schematics::loggers::{Logger, StoringLogger};
+use schematics::loggers::StoringLogger;
 use schematics::resources::{AcmeUser, Cert, Csr, GitCheckout};
 use schematics::symbols::Symbol;
 use schematics::Setup;
 use schematics::SymbolRunner;
+use slog::Logger as SlogLogger;
 use std::cell::RefCell;
 use std::error::Error;
 use std::fmt::Debug;
@@ -18,10 +19,10 @@ struct TestSymbolRunner {
 
 #[async_trait(?Send)]
 impl SymbolRunner for TestSymbolRunner {
-  async fn run_symbol<S: Symbol + Debug, L: Logger>(
+  async fn run_symbol<S: Symbol + Debug>(
     &self,
     _symbol: &S,
-    _logger: &L,
+    _logger: &SlogLogger,
     _force: bool,
   ) -> Result<bool, Box<dyn Error>> {
     *self.count.borrow_mut() += 1;