Better tests

src/loggers.rs

@@ -2,12 +2,13 @@ use std::cell::RefCell;
 use std::cmp::min;
 use std::io::stderr;
 use std::io::Write;
+use std::rc::Rc;
 
 // The log crate defines
 // 1 - Error, 2 - Warn, 3 - Info, 4 - Debug, 5 - Trace
 pub type Level = usize;
 
-#[derive(Clone, Debug)]
+#[derive(Clone, Debug, PartialEq)]
 pub struct Entry<S>(pub Level, pub S);
 
 pub trait Logger {
@@ -100,7 +101,7 @@ impl<'a, L: Logger> Logger for FilteringLogger<'a, L> {
 
 #[derive(Clone, Debug, Default)]
 pub struct StoringLogger {
-  log: RefCell<(bool, Vec<Entry<String>>)>,
+  log: Rc<RefCell<(bool, Vec<Entry<String>>)>>,
 }
 
 impl StoringLogger {
@@ -110,7 +111,7 @@ impl StoringLogger {
   }
 
   pub fn release(self) -> Vec<Entry<String>> {
-    self.log.into_inner().1
+    Rc::try_unwrap(self.log).unwrap().into_inner().1
   }
 }
 

tests/setup.rs

@@ -1,20 +1,25 @@
 use async_trait::async_trait;
+use regex::Regex;
 use schematics::async_utils::{run, sleep};
-use schematics::loggers::StoringLogger;
+use schematics::loggers::{Entry, 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 slog::{info, Logger as SlogLogger};
 use std::error::Error;
 use std::fmt::Debug;
-use std::rc::Rc;
 use std::time::Duration;
 
 #[derive(Clone, Debug)]
 struct TestSymbolRunner {
-  count: Rc<RefCell<usize>>,
+  run: bool,
+}
+
+impl TestSymbolRunner {
+  fn new(run: bool) -> Self {
+    Self { run }
+  }
 }
 
 #[async_trait(?Send)]
@@ -22,33 +27,61 @@ impl SymbolRunner for TestSymbolRunner {
   async fn run_symbol<S: Symbol + Debug>(
     &self,
     _symbol: &S,
-    _logger: &SlogLogger,
+    logger: &SlogLogger,
     _force: bool,
   ) -> Result<bool, Box<dyn Error>> {
-    *self.count.borrow_mut() += 1;
+    info!(logger, "run_symbol");
     sleep(Duration::from_millis(0)).await;
-    Ok(false)
+    Ok(self.run)
+  }
+}
+
+fn test(
+  count: usize,
+  body: fn(setup: Setup<TestSymbolRunner, StoringLogger>) -> (),
+) -> Vec<Entry<String>> {
+  let runner = TestSymbolRunner::new(false);
+  let logger = StoringLogger::new();
+  {
+    let setup = Setup::new(runner, logger.clone());
+    body(setup);
+  }
+  assert_eq!(logger.release(), vec![Entry(3, ".".repeat(count))]);
+
+  let runner = TestSymbolRunner::new(true);
+  let logger = StoringLogger::new();
+  {
+    let setup = Setup::new(runner, logger.clone());
+    body(setup);
   }
+  logger.release()
 }
 
 #[test]
 fn can_create_an_acme_user() {
-  let count = Rc::new(RefCell::new(0));
-  let runner = TestSymbolRunner {
-    count: Rc::clone(&count),
-  };
-  let setup = Setup::new(runner, StoringLogger::new());
+  let mut result = test(1, |setup| {
     assert_eq!((run(setup.add(AcmeUser)).unwrap().0).0, "acme");
+  });
+  let entry = result
+    .pop()
+    .expect("log is empty but should contain one entry");
+  assert_eq!(result.len(), 0, "log has more than one entry");
+  assert_eq!(entry.0, 3, "log entry has wrong level");
+  let re =
+    Regex::new(r"^resource: AcmeUser\n \w+ \d{1,2} \d{2}:\d{2}:\d{2}.\d{3} INFO run_symbol\n$")
+      .unwrap();
+  assert!(
+    re.is_match(&entry.1),
+    "log output {} does not match {}",
+    entry.1,
+    re
+  );
 }
 
 #[test]
 fn runs_only_once() {
+  let mut result = test(2, |setup| {
     run(async {
-    let count = Rc::new(RefCell::new(0));
-    let runner = TestSymbolRunner {
-      count: Rc::clone(&count),
-    };
-    let setup = Setup::new(runner, StoringLogger::new());
       assert_eq!(
         (setup.add(Csr("somehost")).await.unwrap().0)
           .as_ref()
@@ -63,17 +96,24 @@ fn runs_only_once() {
           .unwrap(),
         "/etc/ssl/local_certs/somehost.csr",
       );
-    assert_eq!(*count.borrow(), 2 + 5); // Key and CSR + 5 dirs
     });
+  });
+  let entry = result
+    .pop()
+    .expect("log is empty but should contain entries");
+  assert_eq!(entry.0, 3, "log entry has wrong level");
+  assert_eq!(entry.1, ".", "log entry has wrong content");
+  let entry = result
+    .pop()
+    .expect("log is empty but should contain entries");
+  assert_eq!(entry.0, 3, "log entry has wrong level");
+  assert_eq!(entry.1.matches("run_symbol").count(), 7); // Key and CSR + 5 dirs
+  assert_eq!(result.len(), 0, "log has more than one entry");
 }
 
 #[test]
 fn can_create_an_acme_cert() {
-  let count = Rc::new(RefCell::new(0));
-  let runner = TestSymbolRunner {
-    count: Rc::clone(&count),
-  };
-  let setup = Setup::new(runner, StoringLogger::new());
+  let mut result = test(1, |setup| {
     assert_eq!(
       (run(setup.add(Cert("somehost"))).unwrap().0)
         .as_ref()
@@ -81,21 +121,29 @@ fn can_create_an_acme_cert() {
         .unwrap(),
       "/etc/ssl/local_certs/somehost.crt",
     );
-  assert_eq!(*count.borrow(), 19);
+  });
+  let entry = result
+    .pop()
+    .expect("log is empty but should contain one entry");
+  assert_eq!(entry.0, 3, "log entry has wrong level");
+  assert_eq!(entry.1.matches("run_symbol").count(), 19);
+  assert_eq!(result.len(), 0, "log has more than one entry");
 }
 
 #[test]
 fn can_create_a_git_checkout() {
-  let count = Rc::new(RefCell::new(0));
-  let runner = TestSymbolRunner {
-    count: Rc::clone(&count),
-  };
-  let setup = Setup::new(runner, StoringLogger::new());
+  let mut result = test(1, |setup| {
     run(setup.add(GitCheckout(
       "/tmp/somepath".into(),
       "/tmp/some_src_repo",
       "master",
     )))
     .unwrap();
-  assert_eq!(*count.borrow(), 3);
+  });
+  let entry = result
+    .pop()
+    .expect("log is empty but should contain one entry");
+  assert_eq!(entry.0, 3, "log entry has wrong level");
+  assert_eq!(entry.1.matches("run_symbol").count(), 3);
+  assert_eq!(result.len(), 0, "log has more than one entry");
 }