Command execution tests (#690)

* add zebrad acceptance tests
* add custom command test helpers that work with kill
* add and use info event for start and seed commands
* combine conflicting tests into one test case

Co-authored-by: Jane Lusby <jane@zfnd.org>

Cargo.lock

@@ -2747,6 +2747,9 @@ dependencies = [
  "futures",
  "hex",
  "lazy_static",
+ "regex",
+ "spandoc",
+ "tempdir",
  "thiserror",
  "tokio",
  "tower",
@@ -2799,6 +2802,7 @@ dependencies = [
  "zebra-consensus",
  "zebra-network",
  "zebra-state",
+ "zebra-test",
 ]
 
 [[package]]

zebra-state/Cargo.toml

@@ -29,5 +29,6 @@ zebra-test = { path = "../zebra-test/" }
 
 once_cell = "1.4"
 spandoc = "0.2"
+tracing-futures = "0.2.4"
 tempdir = "0.3.7"
 tokio = { version = "0.2.22", features = ["full"] }

zebra-state/src/on_disk.rs

@@ -45,8 +45,7 @@ impl SledState {
         let height_map = self.storage.open_tree(b"height_map")?;
         let by_hash = self.storage.open_tree(b"by_hash")?;
 
-        let mut bytes = Vec::new();
-        block.zcash_serialize(&mut bytes)?;
+        let bytes = block.zcash_serialize_to_vec()?;
 
         // TODO(jlusby): make this transactional
         height_map.insert(&height.0.to_be_bytes(), &hash.0)?;

zebra-test/Cargo.toml

@@ -16,6 +16,9 @@ color-eyre = "0.5"
 tracing = "0.1.17"
 tracing-subscriber = "0.2.9"
 tracing-error = "0.1.2"
+tempdir = "0.3.7"
+spandoc = "0.2.0"
+regex = "1.3.9"
 thiserror = "1.0.20"
 
 [dev-dependencies]

zebra-test/src/command.rs

@@ -0,0 +1,224 @@
+use color_eyre::{
+    eyre::{eyre, Context, Report, Result},
+    Help, SectionExt,
+};
+use std::process::{Child, Command, ExitStatus, Output};
+use tempdir::TempDir;
+
+/// Runs a command in a TempDir
+pub fn test_cmd(path: &str) -> Result<(Command, impl Drop)> {
+    let dir = TempDir::new(path)?;
+    let mut cmd = Command::new(path);
+    cmd.current_dir(dir.path());
+
+    Ok((cmd, dir))
+}
+
+pub trait CommandExt {
+    /// wrapper for `status` fn on `Command` that constructs informative error
+    /// reports
+    fn status2(&mut self) -> Result<TestStatus, Report>;
+
+    /// wrapper for `output` fn on `Command` that constructs informative error
+    /// reports
+    fn output2(&mut self) -> Result<TestOutput, Report>;
+
+    /// wrapper for `spawn` fn on `Command` that constructs informative error
+    /// reports
+    fn spawn2(&mut self) -> Result<TestChild, Report>;
+}
+
+impl CommandExt for Command {
+    /// wrapper for `status` fn on `Command` that constructs informative error
+    /// reports
+    fn status2(&mut self) -> Result<TestStatus, Report> {
+        let cmd = format!("{:?}", self);
+        let status = self.status();
+
+        let command = || cmd.clone().header("Command:");
+
+        let status = status
+            .wrap_err("failed to execute process")
+            .with_section(command)?;
+
+        Ok(TestStatus { status, cmd })
+    }
+
+    /// wrapper for `output` fn on `Command` that constructs informative error
+    /// reports
+    fn output2(&mut self) -> Result<TestOutput, Report> {
+        let output = self.output();
+
+        let output = output
+            .wrap_err("failed to execute process")
+            .with_section(|| format!("{:?}", self).header("Command:"))?;
+
+        Ok(TestOutput {
+            output,
+            cmd: format!("{:?}", self),
+        })
+    }
+
+    /// wrapper for `spawn` fn on `Command` that constructs informative error
+    /// reports
+    fn spawn2(&mut self) -> Result<TestChild, Report> {
+        let cmd = format!("{:?}", self);
+        let child = self.spawn();
+
+        let child = child
+            .wrap_err("failed to execute process")
+            .with_section(|| cmd.clone().header("Command:"))?;
+
+        Ok(TestChild { child, cmd })
+    }
+}
+
+#[derive(Debug)]
+pub struct TestStatus {
+    pub cmd: String,
+    pub status: ExitStatus,
+}
+
+impl TestStatus {
+    pub fn assert_success(self) -> Result<Self> {
+        assert_success(&self.status, &self.cmd)?;
+
+        Ok(self)
+    }
+
+    pub fn assert_failure(self) -> Result<Self> {
+        assert_failure(&self.status, &self.cmd)?;
+
+        Ok(self)
+    }
+}
+
+fn assert_success(status: &ExitStatus, cmd: &str) -> Result<()> {
+    if !status.success() {
+        let exit_code = || {
+            if let Some(code) = status.code() {
+                format!("Exit Code: {}", code)
+            } else {
+                "Exit Code: None".into()
+            }
+        };
+
+        Err(eyre!("command exited unsuccessfully"))
+            .with_section(|| cmd.to_string().header("Command:"))
+            .with_section(exit_code)?;
+    }
+
+    Ok(())
+}
+
+fn assert_failure(status: &ExitStatus, cmd: &str) -> Result<()> {
+    if status.success() {
+        let exit_code = || {
+            if let Some(code) = status.code() {
+                format!("Exit Code: {}", code)
+            } else {
+                "Exit Code: None".into()
+            }
+        };
+
+        Err(eyre!("command unexpectedly exited successfully"))
+            .with_section(|| cmd.to_string().header("Command:"))
+            .with_section(exit_code)?;
+    }
+
+    Ok(())
+}
+
+#[derive(Debug)]
+pub struct TestChild {
+    pub cmd: String,
+    pub child: Child,
+}
+
+impl TestChild {
+    #[spandoc::spandoc]
+    pub fn kill(&mut self) -> Result<()> {
+        /// SPANDOC: Killing child process
+        self.child
+            .kill()
+            .with_section(|| self.cmd.clone().header("Child Process:"))?;
+
+        Ok(())
+    }
+
+    #[spandoc::spandoc]
+    pub fn wait_with_output(self) -> Result<TestOutput> {
+        let cmd = format!("{:?}", self);
+
+        /// SPANDOC: waiting for command to exit
+        let output = self.child.wait_with_output().with_section({
+            let cmd = cmd.clone();
+            || cmd.header("Command:")
+        })?;
+
+        Ok(TestOutput { output, cmd })
+    }
+}
+
+pub struct TestOutput {
+    pub cmd: String,
+    pub output: Output,
+}
+
+impl TestOutput {
+    pub fn assert_success(self) -> Result<Self> {
+        let output = &self.output;
+
+        assert_success(&self.output.status, &self.cmd)
+            .with_section(|| {
+                String::from_utf8_lossy(output.stdout.as_slice())
+                    .to_string()
+                    .header("Stdout:")
+            })
+            .with_section(|| {
+                String::from_utf8_lossy(output.stderr.as_slice())
+                    .to_string()
+                    .header("Stderr:")
+            })?;
+
+        Ok(self)
+    }
+
+    pub fn assert_failure(self) -> Result<Self> {
+        let output = &self.output;
+
+        assert_failure(&self.output.status, &self.cmd)
+            .with_section(|| {
+                String::from_utf8_lossy(output.stdout.as_slice())
+                    .to_string()
+                    .header("Stdout:")
+            })
+            .with_section(|| {
+                String::from_utf8_lossy(output.stderr.as_slice())
+                    .to_string()
+                    .header("Stderr:")
+            })?;
+
+        Ok(self)
+    }
+
+    pub fn stdout_contains(&self, regex: &str) -> Result<&Self> {
+        let re = regex::Regex::new(regex)?;
+        let stdout = String::from_utf8_lossy(self.output.stdout.as_slice());
+
+        for line in stdout.lines() {
+            if re.is_match(line) {
+                return Ok(self);
+            }
+        }
+
+        let command = || self.cmd.clone().header("Command:");
+        let stdout = || stdout.into_owned().header("Stdout:");
+
+        Err(eyre!(
+            "stdout of command did not contain any matches for the given regex"
+        ))
+        .with_section(command)
+        .with_section(stdout)
+    }
+}

zebra-test/src/lib.rs

@@ -3,6 +3,11 @@ use std::sync::Once;
 use tracing_error::ErrorLayer;
 use tracing_subscriber::{fmt, prelude::*, EnvFilter};
 
+pub mod command;
+pub mod prelude;
+pub mod transcript;
+pub mod vectors;
+
 static INIT: Once = Once::new();
 
 /// Initialize globals for tests such as the tracing subscriber and panic / error
@@ -68,6 +73,3 @@ pub fn init() {
             .unwrap();
     })
 }
-
-pub mod transcript;
-pub mod vectors;

zebra-test/src/prelude.rs

@@ -0,0 +1,5 @@
+pub use crate::command::test_cmd;
+pub use crate::command::CommandExt;
+pub use std::process::Stdio;
+
+pub use tempdir::TempDir;

zebrad/Cargo.toml

@@ -39,3 +39,4 @@ dirs = "3.0.1"
 [dev-dependencies]
 abscissa_core = { version = "0.5", features = ["testing"] }
 once_cell = "1.4"
+zebra-test = { path = "../zebra-test" }

zebrad/src/application.rs

@@ -8,6 +8,7 @@ use abscissa_core::{
     trace::Tracing,
     Application, Component, EntryPoint, FrameworkError, StandardPaths,
 };
+use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
 
 /// Application state
 pub static APPLICATION: AppCell<ZebradApp> = AppCell::new();
@@ -84,13 +85,17 @@ impl Application for ZebradApp {
         &mut self,
         command: &Self::Cmd,
     ) -> Result<Vec<Box<dyn Component<Self>>>, FrameworkError> {
+        let terminal = Terminal::new(self.term_colors(command));
+
+        // This MUST happen after `Terminal::new` to ensure our preferred panic
+        // handler is the last one installed
         color_eyre::install().unwrap();
 
-        let terminal = Terminal::new(self.term_colors(command));
         if ZebradApp::command_is_server(&command) {
             let tracing = self.tracing_component(command);
             Ok(vec![Box::new(terminal), Box::new(tracing)])
         } else {
+            init_tracing_backup();
             Ok(vec![Box::new(terminal)])
         }
     }
@@ -212,8 +217,6 @@ impl ZebradApp {
     }
 
     fn tracing_component(&self, command: &EntryPoint<ZebradCmd>) -> Tracing {
-        use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
-
         // Construct a tracing subscriber with the supplied filter and enable reloading.
         let builder = tracing_subscriber::FmtSubscriber::builder()
             .with_env_filter(self.level(command))
@@ -240,3 +243,9 @@ impl ZebradApp {
         }
     }
 }
+
+fn init_tracing_backup() {
+    tracing_subscriber::Registry::default()
+        .with(tracing_error::ErrorLayer::default())
+        .init();
+}

zebrad/src/commands/seed.rs

@@ -108,6 +108,8 @@ pub struct SeedCmd {}
 impl Runnable for SeedCmd {
     /// Start the application.
     fn run(&self) {
+        info!("Starting zebrad in seed mode");
+
         use crate::components::tokio::TokioComponent;
 
         let rt = app_writer()

zebrad/src/commands/start.rs

@@ -63,6 +63,7 @@ impl StartCmd {
 impl Runnable for StartCmd {
     /// Start the application.
     fn run(&self) {
+        info!("Starting zebrad");
         let rt = app_writer()
             .state_mut()
             .components

zebrad/tests/acceptance.rs

@@ -1,30 +1,261 @@
-//! Acceptance test: runs the application as a subprocess and asserts its
+//! Acceptance test: runs zebrad as a subprocess and asserts its
 //! output for given argument combinations matches what is expected.
-//!
-//! Modify and/or delete these as you see fit to test the specific needs of
-//! your application.
-//!
-//! For more information, see:
-//! <https://docs.rs/abscissa_core/latest/abscissa_core/testing/index.html>
 
-#![deny(warnings, missing_docs, trivial_casts, unused_qualifications)]
+#![warn(warnings, missing_docs, trivial_casts, unused_qualifications)]
 #![forbid(unsafe_code)]
 
-use abscissa_core::testing::prelude::*;
-use once_cell::sync::Lazy;
+use color_eyre::eyre::Result;
+use std::time::Duration;
+use zebra_test::prelude::*;
 
-/// Executes your application binary via `cargo run`.
-pub static RUNNER: Lazy<CmdRunner> = Lazy::new(CmdRunner::default);
+// Todo: The following 3 helper functions can probably be abstracted into one
+pub fn get_child_single_arg(arg: &str) -> Result<(zebra_test::command::TestChild, impl Drop)> {
+    let (mut cmd, guard) = test_cmd(env!("CARGO_BIN_EXE_zebrad"))?;
 
-/*
- * Disabled pending tracing config rework, so that merging abscissa fixes doesn't block on this
- * test failing because there's tracing output.
- *
-/// Example of a test which matches a regular expression
-#[test]
-fn version_no_args() {
-    let mut runner = RUNNER.clone();
-    let mut cmd = runner.arg("version").capture_stdout().run();
-    cmd.stdout().expect_regex(r"\A\w+ [\d\.\-]+\z");
+    Ok((
+        cmd.arg(arg)
+            .stdout(Stdio::piped())
+            .stderr(Stdio::piped())
+            .spawn2()
+            .unwrap(),
+        guard,
+    ))
+}
+
+pub fn get_child_multi_args(args: &[&str]) -> Result<(zebra_test::command::TestChild, impl Drop)> {
+    let (mut cmd, guard) = test_cmd(env!("CARGO_BIN_EXE_zebrad"))?;
+
+    Ok((
+        cmd.args(args)
+            .stdout(Stdio::piped())
+            .stderr(Stdio::piped())
+            .spawn2()
+            .unwrap(),
+        guard,
+    ))
+}
+
+pub fn get_child_no_args() -> Result<(zebra_test::command::TestChild, impl Drop)> {
+    let (mut cmd, guard) = test_cmd(env!("CARGO_BIN_EXE_zebrad"))?;
+
+    Ok((
+        cmd.stdout(Stdio::piped())
+            .stderr(Stdio::piped())
+            .spawn2()
+            .unwrap(),
+        guard,
+    ))
+}
+
+#[test]
+fn generate_no_args() -> Result<()> {
+    zebra_test::init();
+
+    let (child, _guard) = get_child_single_arg("generate")?;
+    let output = child.wait_with_output()?;
+    let output = output.assert_success()?;
+
+    output.stdout_contains(r"# Default configuration for zebrad.")?;
+
+    Ok(())
+}
+
+#[test]
+fn generate_args() -> Result<()> {
+    zebra_test::init();
+
+    // unexpected free argument `argument`
+    let (child, _guard) = get_child_multi_args(&["generate", "argument"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    // unrecognized option `-f`
+    let (child, _guard) = get_child_multi_args(&["generate", "-f"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    // missing argument to option `-o`
+    let (child, _guard) = get_child_multi_args(&["generate", "-o"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    // Valid
+    let (child, _guard) = get_child_multi_args(&["generate", "-o", "file.yaml"])?;
+    let output = child.wait_with_output()?;
+    output.assert_success()?;
+
+    // Todo: Check if the file was created
+
+    Ok(())
+}
+
+#[test]
+fn help_no_args() -> Result<()> {
+    zebra_test::init();
+
+    let (child, _guard) = get_child_single_arg("help")?;
+    let output = child.wait_with_output()?;
+    let output = output.assert_success()?;
+
+    output.stdout_contains(r"USAGE:")?;
+
+    Ok(())
+}
+
+#[test]
+fn help_args() -> Result<()> {
+    zebra_test::init();
+
+    // The subcommand "argument" wasn't recognized.
+    let (child, _guard) = get_child_multi_args(&["help", "argument"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    // option `-f` does not accept an argument
+    let (child, _guard) = get_child_multi_args(&["help", "-f"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    Ok(())
+}
+
+#[test]
+fn revhex_args() -> Result<()> {
+    zebra_test::init();
+
+    // Valid
+    let (child, _guard) = get_child_multi_args(&["revhex", "33eeff55"])?;
+    let output = child.wait_with_output()?;
+    let output = output.assert_success()?;
+
+    output.stdout_contains(r"55ffee33")?;
+
+    Ok(())
+}
+
+fn seed_no_args() -> Result<()> {
+    zebra_test::init();
+
+    let (mut child, _guard) = get_child_single_arg("seed")?;
+
+    // Run the program and kill it at 1 second
+    std::thread::sleep(Duration::from_secs(1));
+    child.kill()?;
+
+    let output = child.wait_with_output()?;
+    let output = output.assert_failure()?;
+
+    output.stdout_contains(r"Starting zebrad in seed mode")?;
+
+    Ok(())
+}
+
+#[test]
+fn seed_args() -> Result<()> {
+    zebra_test::init();
+
+    // unexpected free argument `argument`
+    let (child, _guard) = get_child_multi_args(&["seed", "argument"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    // unrecognized option `-f`
+    let (child, _guard) = get_child_multi_args(&["seed", "-f"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    // unexpected free argument `start`
+    let (child, _guard) = get_child_multi_args(&["seed", "start"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    Ok(())
+}
+
+fn start_no_args() -> Result<()> {
+    zebra_test::init();
+
+    let (mut child, _guard) = get_child_single_arg("start")?;
+
+    // Run the program and kill it at 1 second
+    std::thread::sleep(Duration::from_secs(1));
+    child.kill()?;
+
+    let output = child.wait_with_output()?;
+    let output = output.assert_failure()?;
+
+    output.stdout_contains(r"Starting zebrad")?;
+
+    Ok(())
+}
+
+fn start_args() -> Result<()> {
+    zebra_test::init();
+
+    // Any free argument is valid
+    let (mut child, _guard) = get_child_multi_args(&["start", "argument"])?;
+    // Run the program and kill it at 1 second
+    std::thread::sleep(Duration::from_secs(1));
+    child.kill()?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    // unrecognized option `-f`
+    let (child, _guard) = get_child_multi_args(&["start", "-f"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    Ok(())
+}
+
+#[test]
+fn app_no_args() -> Result<()> {
+    zebra_test::init();
+
+    let (child, _guard) = get_child_no_args()?;
+    let output = child.wait_with_output()?;
+    let output = output.assert_success()?;
+
+    output.stdout_contains(r"USAGE:")?;
+
+    Ok(())
+}
+
+#[test]
+fn version_no_args() -> Result<()> {
+    zebra_test::init();
+
+    let (child, _guard) = get_child_single_arg("version")?;
+    let output = child.wait_with_output()?;
+    let output = output.assert_success()?;
+
+    output.stdout_contains(r"zebrad [0-9].[0-9].[0-9]")?;
+
+    Ok(())
+}
+
+#[test]
+fn version_args() -> Result<()> {
+    zebra_test::init();
+
+    // unexpected free argument `argument`
+    let (child, _guard) = get_child_multi_args(&["version", "argument"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    // unrecognized option `-f`
+    let (child, _guard) = get_child_multi_args(&["version", "-f"])?;
+    let output = child.wait_with_output()?;
+    output.assert_failure()?;
+
+    Ok(())
+}
+
+#[test]
+fn serialized_tests() -> Result<()> {
+    start_no_args()?;
+    start_args()?;
+    seed_no_args()?;
+
+    Ok(())
 }
-*/