From 14e6ec4924ee15d35981380f535a52cb2dc955e2 Mon Sep 17 00:00:00 2001 From: John-John Tedro Date: Wed, 1 Dec 2021 22:00:08 +0100 Subject: [PATCH] Capture output on tests and benches --- crates/rune-cli/src/benches.rs | 70 ++++++++++++++-- crates/rune-cli/src/main.rs | 27 +++++- crates/rune-cli/src/tests.rs | 116 +++++++++++++++----------- crates/rune-modules/Cargo.toml | 3 +- crates/rune-modules/src/capture_io.rs | 16 +++- crates/rune-modules/src/disable_io.rs | 32 +++++++ crates/rune-modules/src/lib.rs | 3 + crates/rune/src/diagnostics/emit.rs | 1 + 8 files changed, 208 insertions(+), 60 deletions(-) create mode 100644 crates/rune-modules/src/disable_io.rs diff --git a/crates/rune-cli/src/benches.rs b/crates/rune-cli/src/benches.rs index e93e0b16f..47ee4ba77 100644 --- a/crates/rune-cli/src/benches.rs +++ b/crates/rune-cli/src/benches.rs @@ -3,6 +3,8 @@ use rune::compile::{Item, Meta}; use rune::runtime::{Function, Unit, Value}; use rune::termcolor::StandardStream; use rune::{Any, Context, ContextError, Hash, Module, Sources}; +use rune_modules::capture_io::CaptureIo; +use std::fmt; use std::io::Write; use std::sync::Arc; use std::time::Instant; @@ -46,6 +48,7 @@ pub(crate) async fn run( o: &mut StandardStream, args: &Flags, context: &Context, + io: Option<&CaptureIo>, unit: Arc, sources: &Sources, fns: &[(Hash, Meta)], @@ -58,18 +61,35 @@ pub(crate) async fn run( let mut any_error = false; for (hash, meta) in fns { + let item = &meta.item.item; let mut bencher = Bencher::default(); if let Err(error) = vm.call(*hash, (&mut bencher,)) { - writeln!(o, "Error in benchmark `{}`", meta.item.item)?; + writeln!(o, "{}: Error in benchmark", item)?; error.emit(o, sources)?; any_error = true; + + if let Some(io) = io { + writeln!(o, "-- output --")?; + io.drain_into(&mut *o)?; + writeln!(o, "-- end output --")?; + } + continue; } + let multiple = bencher.fns.len() > 1; + for (i, f) in bencher.fns.iter().enumerate() { - if let Err(e) = bench_fn(o, i, &meta.item.item, args, f) { - writeln!(o, "Error running benchmark iteration: {}", e)?; + if let Err(e) = bench_fn(o, i, item, args, f, multiple) { + writeln!(o, "{}: Error in bench iteration: {}", item, e)?; + + if let Some(io) = io { + writeln!(o, "-- output --")?; + io.drain_into(&mut *o)?; + writeln!(o, "-- end output --")?; + } + any_error = true; } } @@ -88,6 +108,7 @@ fn bench_fn( item: &Item, args: &Flags, f: &Function, + multiple: bool, ) -> anyhow::Result<()> { for _ in 0..args.warmup { let value = f.call::<_, Value>(())?; @@ -117,10 +138,43 @@ fn bench_fn( / len; let stddev = variance.sqrt(); - writeln!( - o, - "bench {}#{}: mean={:.2}ns, stddev={:.2}, iterations={}", - item, i, average, stddev, args.iterations, - )?; + let format = Format { + average: average as u128, + stddev: stddev as u128, + iterations, + }; + + if multiple { + writeln!(o, "bench {}#{}: {}", item, i, format)?; + } else { + writeln!(o, "bench {}: {}", item, format)?; + } + Ok(()) } + +struct Format { + average: u128, + stddev: u128, + iterations: usize, +} + +impl fmt::Display for Format { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!( + f, + "mean={:.2}, stddev={:.2}, iterations={}", + Time(self.average), + Time(self.stddev), + self.iterations + ) + } +} + +struct Time(u128); + +impl fmt::Display for Time { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!(f, "{}ns", self.0) + } +} diff --git a/crates/rune-cli/src/main.rs b/crates/rune-cli/src/main.rs index 7c8e95647..9ecf12bad 100644 --- a/crates/rune-cli/src/main.rs +++ b/crates/rune-cli/src/main.rs @@ -53,6 +53,7 @@ use anyhow::Result; use rune::compile::ParseOptionError; use rune::termcolor::{Color, ColorChoice, ColorSpec, StandardStream, WriteColor}; use rune::{Context, ContextError, Options}; +use rune_modules::capture_io::CaptureIo; use std::error::Error; use std::io::{self, Write}; use std::path::{Path, PathBuf}; @@ -151,6 +152,23 @@ impl SharedFlags { Ok(context) } + + /// Setup a context that captures output. + fn context_with_capture(&self, io: &CaptureIo) -> Result { + let mut context = rune_modules::with_config(false)?; + + context.install(&rune_modules::capture_io::module(io)?)?; + + if self.experimental { + context.install(&rune_modules::experiments::module(true)?)?; + } + + if self.test { + context.install(&benches::test_module()?)?; + } + + Ok(context) + } } #[derive(Debug, Clone, StructOpt)] @@ -180,6 +198,7 @@ impl Args { // Command-specific override defaults. match &self.cmd { Command::Test(_) | Command::Check(_) => { + options.debug_info(true); options.test(true); options.bytecode(false); } @@ -362,7 +381,8 @@ async fn run_path( match &args.cmd { Command::Check(flags) => check::run(o, flags, options, path), Command::Test(flags) => { - let context = flags.shared.context()?; + let io = rune_modules::capture_io::CaptureIo::new(); + let context = flags.shared.context_with_capture(&io)?; let load = loader::load(o, &context, args, options, path, visitor::Attribute::Test)?; @@ -370,6 +390,7 @@ async fn run_path( o, flags, &context, + Some(&io), load.unit, &load.sources, &load.functions, @@ -377,7 +398,8 @@ async fn run_path( .await } Command::Bench(flags) => { - let context = flags.shared.context()?; + let io = rune_modules::capture_io::CaptureIo::new(); + let context = flags.shared.context_with_capture(&io)?; let load = loader::load(o, &context, args, options, path, visitor::Attribute::Bench)?; @@ -385,6 +407,7 @@ async fn run_path( o, flags, &context, + Some(&io), load.unit, &load.sources, &load.functions, diff --git a/crates/rune-cli/src/tests.rs b/crates/rune-cli/src/tests.rs index 8fbfb029c..80b58861a 100644 --- a/crates/rune-cli/src/tests.rs +++ b/crates/rune-cli/src/tests.rs @@ -1,8 +1,10 @@ use crate::{ExitCode, SharedFlags}; +use anyhow::Result; use rune::compile::Meta; use rune::runtime::{Unit, Value, Vm, VmError}; use rune::termcolor::StandardStream; use rune::{Context, Hash, Sources}; +use rune_modules::capture_io::CaptureIo; use std::io::Write; use std::sync::Arc; use std::time::Instant; @@ -25,8 +27,8 @@ pub(crate) struct Flags { #[derive(Debug)] enum FailureReason { Crash(VmError), - ReturnedNone, - ReturnedErr(Value), + ReturnedNone { output: Box<[u8]> }, + ReturnedErr { output: Box<[u8]>, error: Value }, } #[derive(Debug)] @@ -34,6 +36,7 @@ struct TestCase<'a> { hash: Hash, meta: &'a Meta, outcome: Option, + buf: Vec, } impl<'a> TestCase<'a> { @@ -42,88 +45,106 @@ impl<'a> TestCase<'a> { hash, meta, outcome: None, + buf: Vec::new(), } } - fn start(&self, o: &mut StandardStream, quiet: bool) -> Result<(), std::io::Error> { - if quiet { - return Ok(()); + async fn execute( + &mut self, + o: &mut StandardStream, + vm: &mut Vm, + quiet: bool, + io: Option<&CaptureIo>, + ) -> Result { + if !quiet { + write!(o, "Test {:30} ", self.meta.item.item)?; } - write!(o, "Test {:30} ", self.meta.item.item) - } - - async fn execute(&mut self, vm: &mut Vm) -> Result { let result = match vm.execute(self.hash, ()) { Err(err) => Err(err), Ok(mut execution) => execution.async_complete().await, }; + if let Some(io) = io { + let _ = io.drain_into(&mut self.buf); + } + self.outcome = match result { Err(e) => Some(FailureReason::Crash(e)), Ok(v) => match v { Value::Result(result) => match result.take()? { Ok(..) => None, - Err(err) => Some(FailureReason::ReturnedErr(err)), + Err(error) => Some(FailureReason::ReturnedErr { + output: self.buf.as_slice().into(), + error, + }), }, Value::Option(option) => match *option.borrow_ref()? { Some(..) => None, - None => Some(FailureReason::ReturnedNone), + None => Some(FailureReason::ReturnedNone { + output: self.buf.as_slice().into(), + }), }, _ => None, }, }; - Ok(self.outcome.is_none()) - } - - fn end(&self, o: &mut StandardStream, quiet: bool) -> Result<(), std::io::Error> { if quiet { match &self.outcome { - Some(FailureReason::Crash(_)) => { - write!(o, "F") + Some(FailureReason::Crash { .. }) => { + write!(o, "F")?; } - Some(FailureReason::ReturnedErr(_)) => { - write!(o, "f") + Some(FailureReason::ReturnedErr { .. }) => { + write!(o, "f")?; } - Some(FailureReason::ReturnedNone) => { - write!(o, "n") + Some(FailureReason::ReturnedNone { .. }) => { + write!(o, "n")?; + } + None => { + write!(o, ".")?; } - None => write!(o, "."), } } else { match &self.outcome { - Some(FailureReason::Crash(_)) => { - writeln!(o, "failed") + Some(FailureReason::Crash { .. }) => { + writeln!(o, "failed")?; + } + Some(FailureReason::ReturnedErr { .. }) => { + writeln!(o, "returned error")?; } - Some(FailureReason::ReturnedErr(_)) => { - writeln!(o, "returned error") + Some(FailureReason::ReturnedNone { .. }) => { + writeln!(o, "returned none")?; } - Some(FailureReason::ReturnedNone) => { - writeln!(o, "returned none") + None => { + writeln!(o, "passed")?; } - None => writeln!(o, "passed"), } } + + self.buf.clear(); + Ok(self.outcome.is_none()) } - fn emit(&self, o: &mut StandardStream, sources: &Sources) -> Result<(), std::io::Error> { - if self.outcome.is_none() { - return Ok(()); - } - match self.outcome.as_ref().unwrap() { - FailureReason::Crash(err) => { - writeln!(o, "----------------------------------------")?; - writeln!(o, "Test: {}\n", self.meta.item.item)?; - err.emit(o, sources).expect("failed writing diagnostics"); - } - FailureReason::ReturnedNone => {} - FailureReason::ReturnedErr(e) => { - writeln!(o, "----------------------------------------")?; - writeln!(o, "Test: {}\n", self.meta.item.item)?; - writeln!(o, "Error: {:?}\n", e)?; + fn emit(&self, o: &mut StandardStream, sources: &Sources) -> Result<()> { + if let Some(outcome) = &self.outcome { + match outcome { + FailureReason::Crash(err) => { + writeln!(o, "----------------------------------------")?; + writeln!(o, "Test: {}\n", self.meta.item.item)?; + err.emit(o, sources)?; + } + FailureReason::ReturnedNone { .. } => {} + FailureReason::ReturnedErr { output, error, .. } => { + writeln!(o, "----------------------------------------")?; + writeln!(o, "Test: {}\n", self.meta.item.item)?; + writeln!(o, "Error: {:?}\n", error)?; + writeln!(o, "-- output --")?; + o.write_all(output)?; + writeln!(o, "-- end of output --")?; + } } } + Ok(()) } } @@ -132,6 +153,7 @@ pub(crate) async fn run( o: &mut StandardStream, flags: &Flags, context: &Context, + io: Option<&CaptureIo>, unit: Arc, sources: &Sources, fns: &[(Hash, Meta)], @@ -154,11 +176,11 @@ pub(crate) async fn run( for test in &mut cases { executed_count += 1; - test.start(o, flags.quiet)?; - let success = test.execute(&mut vm).await?; - test.end(o, flags.quiet)?; + let success = test.execute(o, &mut vm, flags.quiet, io).await?; + if !success { failure_count += 1; + if !flags.no_fail_fast { break; } diff --git a/crates/rune-modules/Cargo.toml b/crates/rune-modules/Cargo.toml index bc815ec7a..c06787bc4 100644 --- a/crates/rune-modules/Cargo.toml +++ b/crates/rune-modules/Cargo.toml @@ -15,7 +15,7 @@ Native modules for Rune, an embeddable dynamic programming language for Rust. """ [features] -default = ["test", "core", "io", "fmt", "macros"] +default = ["test", "core", "io", "fmt", "macros", "disable-io"] full = ["time", "http", "json", "toml", "fs", "process", "signal", "rand", "io", "fmt", "macros"] time = ["tokio", "tokio/time"] fs = ["tokio", "tokio/fs"] @@ -26,6 +26,7 @@ signal = ["tokio/signal"] rand = ["nanorand"] experiments = [] capture-io = ["parking_lot"] +disable-io = [] test = [] core = [] io = [] diff --git a/crates/rune-modules/src/capture_io.rs b/crates/rune-modules/src/capture_io.rs index 5412432a4..bd962cfea 100644 --- a/crates/rune-modules/src/capture_io.rs +++ b/crates/rune-modules/src/capture_io.rs @@ -7,7 +7,7 @@ //! # fn main() -> Result<(), ContextError> { //! let io = CaptureIo::new(); //! -//! let mut c = Context::new(); +//! let mut c = rune_modules::with_config(false)?; //! c.install(&capture_io::module(&io)?)?; //! # Ok(()) } //! ``` @@ -15,7 +15,7 @@ use parking_lot::Mutex; use rune::runtime::{Panic, Stack, VmError}; use rune::{ContextError, Module, Value}; -use std::io::Write; +use std::io::{self, Write}; use std::string::FromUtf8Error; use std::sync::Arc; @@ -36,6 +36,18 @@ impl CaptureIo { std::mem::take(&mut *o) } + /// Drain all captured I/O that has been written to output functions into + /// the given [Write]. + pub fn drain_into(&self, mut out: O) -> io::Result<()> + where + O: Write, + { + let mut o = self.inner.lock(); + out.write_all(&*o)?; + o.clear(); + Ok(()) + } + /// Drain all captured I/O that has been written to output functions and try /// to decode as UTF-8. pub fn drain_utf8(&self) -> Result { diff --git a/crates/rune-modules/src/disable_io.rs b/crates/rune-modules/src/disable_io.rs new file mode 100644 index 000000000..452bd2ee4 --- /dev/null +++ b/crates/rune-modules/src/disable_io.rs @@ -0,0 +1,32 @@ +//! I/O module ignoring everything written to output. +//! +//! ``` +//! use rune::{Context, ContextError}; +//! use rune_modules::disable_io; +//! +//! # fn main() -> Result<(), ContextError> { +//! let mut c = rune_modules::with_config(false)?; +//! c.install(&disable_io::module()?)?; +//! # Ok(()) } +//! ``` + +use rune::runtime::Stack; +use rune::{ContextError, Module}; + +/// Provide a bunch of `std::io` functions which will cause any output to be ignored. +pub fn module() -> Result { + let mut module = Module::with_crate_item("std", &["io"]); + + module.function(&["print"], move |_: &str| {})?; + + module.function(&["println"], move |_: &str| {})?; + + module.raw_fn(&["dbg"], move |stack: &mut Stack, args: usize| { + // NB: still need to maintain the stack. + drop(stack.drain(args)?); + stack.push(()); + Ok(()) + })?; + + Ok(module) +} diff --git a/crates/rune-modules/src/lib.rs b/crates/rune-modules/src/lib.rs index f80a5188d..948bf1c0d 100644 --- a/crates/rune-modules/src/lib.rs +++ b/crates/rune-modules/src/lib.rs @@ -103,6 +103,9 @@ pub mod experiments; #[cfg(feature = "capture-io")] pub mod capture_io; +#[cfg(feature = "disable-io")] +pub mod disable_io; + macro_rules! modules { ($($ident:ident, $name:literal),* $(,)?) => { $( diff --git a/crates/rune/src/diagnostics/emit.rs b/crates/rune/src/diagnostics/emit.rs index d52998bee..b22aa1ecd 100644 --- a/crates/rune/src/diagnostics/emit.rs +++ b/crates/rune/src/diagnostics/emit.rs @@ -108,6 +108,7 @@ impl VmError { return Ok(()); } }; + let debug_inst = match debug_info.instruction_at(ip) { Some(debug_inst) => debug_inst, None => {