From 02c0c68ed27d5ebc1f6d5211726a6199c0601e1a Mon Sep 17 00:00:00 2001 From: Pat Hickey Date: Tue, 2 Jun 2020 12:24:28 -0700 Subject: [PATCH] replace all uses of `log` with `tracing` --- Cargo.lock | 1 + crates/wiggle/Cargo.toml | 12 +- crates/wiggle/generate/src/config.rs | 49 ------ crates/wiggle/generate/src/funcs.rs | 142 +++++++----------- crates/wiggle/generate/src/lib.rs | 12 +- crates/wiggle/generate/src/types/enum.rs | 6 + crates/wiggle/generate/src/types/flags.rs | 6 + crates/wiggle/generate/src/types/handle.rs | 6 + crates/wiggle/generate/src/types/int.rs | 6 + crates/wiggle/generate/src/types/mod.rs | 53 +++++++ crates/wiggle/generate/src/types/struct.rs | 6 + crates/wiggle/generate/src/types/union.rs | 6 + crates/wiggle/macro/src/lib.rs | 2 +- crates/wiggle/src/lib.rs | 1 + crates/wiggle/src/tracing.rs | 11 ++ .../wiggle/test-helpers/examples/tracing.rs | 118 +++++++++++++++ 16 files changed, 285 insertions(+), 152 deletions(-) create mode 100644 crates/wiggle/src/tracing.rs create mode 100644 crates/wiggle/test-helpers/examples/tracing.rs diff --git a/Cargo.lock b/Cargo.lock index 782cffd7b8..3870242c33 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2623,6 +2623,7 @@ version = "0.17.0" dependencies = [ "proptest", "thiserror", + "tracing", "wiggle-macro", "wiggle-test", "witx", diff --git a/crates/wiggle/Cargo.toml b/crates/wiggle/Cargo.toml index c6f6adb427..07566bb338 100644 --- a/crates/wiggle/Cargo.toml +++ b/crates/wiggle/Cargo.toml @@ -14,6 +14,7 @@ include = ["src/**/*", "LICENSE"] thiserror = "1" witx = { path = "../wasi-common/WASI/tools/witx", version = "0.8.5", optional = true } wiggle-macro = { path = "macro", version = "0.17.0" } +tracing_crate = { version = "0.1.14", optional = true, package = "tracing" } [badges] maintenance = { status = "actively-developed" } @@ -23,13 +24,14 @@ wiggle-test = { path = "test-helpers" } proptest = "0.9" [features] -# These features have no effect on the users of this crate. They are only -# necessary for testing. # The wiggle proc-macro emits some code (inside `pub mod metadata`) guarded # by the `wiggle_metadata` feature flag. We use this feature flag so that # users of wiggle are not forced to take a direct dependency on the `witx` # crate unless they want it. wiggle_metadata = ['witx', "wiggle-macro/wiggle_metadata"] -# In order to test that the contents of this metadata module meet -# expectations, we must have this feature enabled for the crate by default. -default = ["wiggle_metadata"] +# The wiggle proc-macro emits code which may transitively depend on the +# `tracing` crate, via `wiggle::tracing`. When this feature is not enabled, +# a no-op equivelant to the tracing macros is provided instead. +tracing = [ "tracing_crate" ] + +default = ["wiggle_metadata", "tracing"] diff --git a/crates/wiggle/generate/src/config.rs b/crates/wiggle/generate/src/config.rs index 8769504780..22ff88aa24 100644 --- a/crates/wiggle/generate/src/config.rs +++ b/crates/wiggle/generate/src/config.rs @@ -18,7 +18,6 @@ pub struct Config { pub witx: WitxConf, pub ctx: CtxConf, pub errors: ErrorConf, - pub logging: LoggingConf, } #[derive(Debug, Clone)] @@ -26,17 +25,13 @@ pub enum ConfigField { Witx(WitxConf), Ctx(CtxConf), Error(ErrorConf), - Logging(LoggingConf), } mod kw { syn::custom_keyword!(witx); syn::custom_keyword!(witx_literal); syn::custom_keyword!(ctx); - syn::custom_keyword!(logging); syn::custom_keyword!(errors); - syn::custom_keyword!(log); - syn::custom_keyword!(tracing); } impl Parse for ConfigField { @@ -54,10 +49,6 @@ impl Parse for ConfigField { input.parse::()?; input.parse::()?; Ok(ConfigField::Ctx(input.parse()?)) - } else if lookahead.peek(kw::logging) { - input.parse::()?; - input.parse::()?; - Ok(ConfigField::Logging(input.parse()?)) } else if lookahead.peek(kw::errors) { input.parse::()?; input.parse::()?; @@ -73,7 +64,6 @@ impl Config { let mut witx = None; let mut ctx = None; let mut errors = None; - let mut logging = None; for f in fields { match f { ConfigField::Witx(c) => { @@ -94,12 +84,6 @@ impl Config { } errors = Some(c); } - ConfigField::Logging(c) => { - if logging.is_some() { - return Err(Error::new(err_loc, "duplicate `logging` field")); - } - logging = Some(c); - } } } Ok(Config { @@ -110,7 +94,6 @@ impl Config { .take() .ok_or_else(|| Error::new(err_loc, "`ctx` field required"))?, errors: errors.take().unwrap_or_default(), - logging: logging.take().unwrap_or_default(), }) } @@ -319,35 +302,3 @@ impl Parse for ErrorConfField { }) } } - -/// Configure logging statements in generated code -#[derive(Debug, Clone)] -pub enum LoggingConf { - Log { cfg_feature: Option }, - Tracing, -} - -impl Default for LoggingConf { - fn default() -> Self { - // For compatibility with existing code. We should probably revise this later. - LoggingConf::Log { - cfg_feature: Some("trace_log".to_owned()), - } - } -} - -impl Parse for LoggingConf { - fn parse(input: ParseStream) -> Result { - let lookahead = input.lookahead1(); - if lookahead.peek(kw::log) { - input.parse::()?; - // TODO: syntax so the user can specify their own cfg_feature guard here. - Ok(LoggingConf::Log { cfg_feature: None }) - } else if lookahead.peek(kw::tracing) { - input.parse::()?; - Ok(LoggingConf::Tracing) - } else { - Err(lookahead.error()) - } - } -} diff --git a/crates/wiggle/generate/src/funcs.rs b/crates/wiggle/generate/src/funcs.rs index 33827b75b6..0baa8cd390 100644 --- a/crates/wiggle/generate/src/funcs.rs +++ b/crates/wiggle/generate/src/funcs.rs @@ -1,18 +1,17 @@ use proc_macro2::TokenStream; use quote::quote; -use crate::config::LoggingConf; use crate::error_transform::ErrorTransform; use crate::lifetimes::anon_lifetime; use crate::module_trait::passed_by_reference; use crate::names::Names; +use crate::types::WiggleType; pub fn define_func( names: &Names, + module: &witx::Module, func: &witx::InterfaceFunc, - trait_name: TokenStream, errxform: &ErrorTransform, - logging: &LoggingConf, ) -> TokenStream { let funcname = func.name.as_str(); @@ -51,19 +50,20 @@ pub fn define_func( let ret_err = coretype .ret .map(|ret| { - let name = ret.param.name.as_str(); + let name = names.func_param(&ret.param.name); let conversion = if let Some(user_err) = errxform.for_abi_error(&ret.param.tref) { let method = names.user_error_conversion_method(&user_err); - quote!(#abi_ret::from(UserErrorConversion::#method(ctx, e))) + quote!(UserErrorConversion::#method(ctx, e)) } else { - quote!(#abi_ret::from(e)) + quote!(e) }; quote! { - #[cfg(feature = "trace_log")] - { - log::trace!(" | {}={:?}", #name, e); - } - return #conversion; + let e = #conversion; + #rt::tracing::event!( + #rt::tracing::Level::TRACE, + #name = #rt::tracing::field::debug(&e), + ); + return #abi_ret::from(e); } }) .unwrap_or_else(|| quote!(())); @@ -78,7 +78,7 @@ pub fn define_func( let err_method = names.guest_error_conversion_method(&tref); quote! { let e = #rt::GuestError::InFunc { funcname: #funcname, location: #location, err: Box::new(e.into()) }; - let err: #err_typename = GuestErrorConversion::#err_method(ctx, e); // XXX replace with conversion method on trait! + let err: #err_typename = GuestErrorConversion::#err_method(ctx, e); return #abi_ret::from(err); } } else { @@ -101,6 +101,23 @@ pub fn define_func( } }); + let log_marshalled_args = if func.params.len() > 0 { + let rt = names.runtime_mod(); + let args = func.params.iter().map(|param| { + let name = names.func_param(¶m.name); + if param.impls_display() { + quote!( #name = #rt::tracing::field::display(&#name) ) + } else { + quote!( #name = #rt::tracing::field::debug(&#name) ) + } + }); + quote! { + #rt::tracing::event!(#rt::tracing::Level::TRACE, #(#args),*); + } + } else { + quote!() + }; + let (trait_rets, trait_bindings) = if func.results.len() < 2 { (quote!({}), quote!(_)) } else { @@ -111,29 +128,16 @@ pub fn define_func( .map(|result| names.func_param(&result.name)) .collect(); let bindings = quote!((#(#trait_rets),*)); - let names: Vec<_> = func - .results - .iter() - .skip(1) - .map(|result| { - let name = names.func_param(&result.name); - let fmt = match &*result.tref.type_() { - witx::Type::Builtin(_) - | witx::Type::Enum(_) - | witx::Type::Flags(_) - | witx::Type::Handle(_) - | witx::Type::Int(_) => "{}", - _ => "{:?}", - }; - format!("{}={}", name.to_string(), fmt) - }) - .collect(); - let trace_fmt = format!(" | result=({})", names.join(",")); - let rets = quote! { - #[cfg(feature = "trace_log")] - { - log::trace!(#trace_fmt, #(#trait_rets),*); + let trace_rets = func.results.iter().skip(1).map(|result| { + let name = names.func_param(&result.name); + if result.tref.impls_display() { + quote!(#name = #rt::tracing::field::display(&#name)) + } else { + quote!(#name = #rt::tracing::field::debug(&#name)) } + }); + let rets = quote! { + #rt::tracing::event!(#rt::tracing::Level::TRACE, #(#trace_rets),*); (#(#trait_rets),*) }; (rets, bindings) @@ -153,22 +157,32 @@ pub fn define_func( let err_typename = names.type_ref(&err_type, anon_lifetime()); quote! { let success:#err_typename = #rt::GuestErrorType::success(); - #[cfg(feature = "trace_log")] - { - log::trace!(" | errno={}", success); - } + #rt::tracing::event!( + #rt::tracing::Level::TRACE, + success=#rt::tracing::field::display(&success) + ); #abi_ret::from(success) } } else { quote!() }; - let log_args = logging.args(&func, names); + let trait_name = names.trait_name(&module.name); + let mod_name = &module.name.as_str(); + let func_name = &func.name.as_str(); quote!(pub fn #ident(#abi_args) -> #abi_ret { + let _span = #rt::tracing::span!( + #rt::tracing::Level::TRACE, + "wiggle abi", + module = #mod_name, + function = #func_name + ); + let _enter = _span.enter(); + #(#marshal_args)* #(#marshal_rets_pre)* - #log_args + #log_marshalled_args let #trait_bindings = match #trait_name::#ident(ctx, #(#trait_args),*) { Ok(#trait_bindings) => { #trait_rets }, Err(e) => { #ret_err }, @@ -323,51 +337,3 @@ where _ => write_val_to_ptr, } } - -impl LoggingConf { - fn args(&self, func: &witx::InterfaceFunc, names: &Names) -> TokenStream { - match self { - Self::Log { cfg_feature } => { - let (placeholders, args): (Vec<_>, Vec<_>) = func - .params - .iter() - .map(|param| { - let name = names.func_param(¶m.name); - let fmt = if passed_by_reference(&*param.tref.type_()) { - "{:?}" - } else { - "{}" - }; - (format!("{}={}", name.to_string(), fmt), quote!(#name)) - }) - .unzip(); - let trace_fmt = format!( - "{}({})", - names.func(&func.name).to_string(), - placeholders.join(",") - ); - let trace_stmt = quote!(log::trace!(#trace_fmt, #(#args),*);); - if let Some(feature) = cfg_feature { - quote! { - #[cfg(feature = #feature)] - { - #trace_stmt - } - } - } else { - trace_stmt - } - } - Self::Tracing => { - let args = func.params.iter().map(|param| { - let name = names.func_param(¶m.name); - quote!( #name = #name ) - }); - let func_name = names.func(&func.name).to_string(); - quote! { - tracing::debug!(function = #func_name, #(#args),*, "marshalled arguments"); - } - } - } - } -} diff --git a/crates/wiggle/generate/src/lib.rs b/crates/wiggle/generate/src/lib.rs index 459d22f472..f1913163c7 100644 --- a/crates/wiggle/generate/src/lib.rs +++ b/crates/wiggle/generate/src/lib.rs @@ -11,19 +11,14 @@ use quote::quote; use lifetimes::anon_lifetime; -pub use config::{Config, LoggingConf}; +pub use config::Config; pub use error_transform::{ErrorTransform, UserErrorType}; pub use funcs::define_func; pub use module_trait::define_module_trait; pub use names::Names; pub use types::define_datatype; -pub fn generate( - doc: &witx::Document, - names: &Names, - errs: &ErrorTransform, - logging: &LoggingConf, -) -> TokenStream { +pub fn generate(doc: &witx::Document, names: &Names, errs: &ErrorTransform) -> TokenStream { // TODO at some point config should grow more ability to configure name // overrides. let rt = names.runtime_mod(); @@ -54,10 +49,9 @@ pub fn generate( }; let modules = doc.modules().map(|module| { let modname = names.module(&module.name); - let trait_name = names.trait_name(&module.name); let fs = module .funcs() - .map(|f| define_func(&names, &f, quote!(#trait_name), &errs, logging)); + .map(|f| define_func(&names, &module, &f, &errs)); let modtrait = define_module_trait(&names, &module, &errs); let ctx_type = names.ctx_type(); quote!( diff --git a/crates/wiggle/generate/src/types/enum.rs b/crates/wiggle/generate/src/types/enum.rs index a3a0096047..cef56065ef 100644 --- a/crates/wiggle/generate/src/types/enum.rs +++ b/crates/wiggle/generate/src/types/enum.rs @@ -112,3 +112,9 @@ pub(super) fn define_enum(names: &Names, name: &witx::Id, e: &witx::EnumDatatype } } } + +impl super::WiggleType for witx::EnumDatatype { + fn impls_display(&self) -> bool { + true + } +} diff --git a/crates/wiggle/generate/src/types/flags.rs b/crates/wiggle/generate/src/types/flags.rs index 7759e7e6a2..f87261abca 100644 --- a/crates/wiggle/generate/src/types/flags.rs +++ b/crates/wiggle/generate/src/types/flags.rs @@ -180,3 +180,9 @@ pub(super) fn define_flags(names: &Names, name: &witx::Id, f: &witx::FlagsDataty } } + +impl super::WiggleType for witx::FlagsDatatype { + fn impls_display(&self) -> bool { + true + } +} diff --git a/crates/wiggle/generate/src/types/handle.rs b/crates/wiggle/generate/src/types/handle.rs index c28b77d885..310c9e7d6e 100644 --- a/crates/wiggle/generate/src/types/handle.rs +++ b/crates/wiggle/generate/src/types/handle.rs @@ -82,3 +82,9 @@ pub(super) fn define_handle( } } + +impl super::WiggleType for witx::HandleDatatype { + fn impls_display(&self) -> bool { + true + } +} diff --git a/crates/wiggle/generate/src/types/int.rs b/crates/wiggle/generate/src/types/int.rs index 43e6997683..d916b65b70 100644 --- a/crates/wiggle/generate/src/types/int.rs +++ b/crates/wiggle/generate/src/types/int.rs @@ -92,3 +92,9 @@ pub(super) fn define_int(names: &Names, name: &witx::Id, i: &witx::IntDatatype) } } + +impl super::WiggleType for witx::IntDatatype { + fn impls_display(&self) -> bool { + true + } +} diff --git a/crates/wiggle/generate/src/types/mod.rs b/crates/wiggle/generate/src/types/mod.rs index 19b8aa9489..6ed29af94b 100644 --- a/crates/wiggle/generate/src/types/mod.rs +++ b/crates/wiggle/generate/src/types/mod.rs @@ -91,3 +91,56 @@ fn atom_token(atom: witx::AtomType) -> TokenStream { witx::AtomType::F64 => quote!(f64), } } + +pub trait WiggleType { + fn impls_display(&self) -> bool; +} + +impl WiggleType for witx::TypeRef { + fn impls_display(&self) -> bool { + match self { + witx::TypeRef::Name(alias_to) => (&*alias_to).impls_display(), + witx::TypeRef::Value(v) => (&*v).impls_display(), + } + } +} + +impl WiggleType for witx::NamedType { + fn impls_display(&self) -> bool { + self.tref.impls_display() + } +} + +impl WiggleType for witx::Type { + fn impls_display(&self) -> bool { + match self { + witx::Type::Enum(x) => x.impls_display(), + witx::Type::Int(x) => x.impls_display(), + witx::Type::Flags(x) => x.impls_display(), + witx::Type::Struct(x) => x.impls_display(), + witx::Type::Union(x) => x.impls_display(), + witx::Type::Handle(x) => x.impls_display(), + witx::Type::Builtin(x) => x.impls_display(), + witx::Type::Pointer { .. } + | witx::Type::ConstPointer { .. } + | witx::Type::Array { .. } => false, + } + } +} + +impl WiggleType for witx::BuiltinType { + fn impls_display(&self) -> bool { + true + } +} + +impl WiggleType for witx::InterfaceFuncParam { + fn impls_display(&self) -> bool { + match &*self.tref.type_() { + witx::Type::Struct { .. } + | witx::Type::Union { .. } + | witx::Type::Builtin(witx::BuiltinType::String { .. }) => false, + _ => self.tref.impls_display(), + } + } +} diff --git a/crates/wiggle/generate/src/types/struct.rs b/crates/wiggle/generate/src/types/struct.rs index 47cd32d1e5..5b3a025904 100644 --- a/crates/wiggle/generate/src/types/struct.rs +++ b/crates/wiggle/generate/src/types/struct.rs @@ -133,3 +133,9 @@ pub(super) fn define_struct( #transparent } } + +impl super::WiggleType for witx::StructDatatype { + fn impls_display(&self) -> bool { + false + } +} diff --git a/crates/wiggle/generate/src/types/union.rs b/crates/wiggle/generate/src/types/union.rs index 0c357756eb..ecc3253f3c 100644 --- a/crates/wiggle/generate/src/types/union.rs +++ b/crates/wiggle/generate/src/types/union.rs @@ -108,3 +108,9 @@ pub(super) fn define_union(names: &Names, name: &witx::Id, u: &witx::UnionDataty } } } + +impl super::WiggleType for witx::UnionDatatype { + fn impls_display(&self) -> bool { + false + } +} diff --git a/crates/wiggle/macro/src/lib.rs b/crates/wiggle/macro/src/lib.rs index fced356f34..ed4a3dc6f0 100644 --- a/crates/wiggle/macro/src/lib.rs +++ b/crates/wiggle/macro/src/lib.rs @@ -101,7 +101,7 @@ pub fn from_witx(args: TokenStream) -> TokenStream { let error_transform = wiggle_generate::ErrorTransform::new(&config.errors, &doc) .expect("validating error transform"); - let code = wiggle_generate::generate(&doc, &names, &error_transform, &config.logging); + let code = wiggle_generate::generate(&doc, &names, &error_transform); let metadata = if cfg!(feature = "wiggle_metadata") { wiggle_generate::generate_metadata(&doc, &names) } else { diff --git a/crates/wiggle/src/lib.rs b/crates/wiggle/src/lib.rs index 000080ad86..9e6e9933fa 100644 --- a/crates/wiggle/src/lib.rs +++ b/crates/wiggle/src/lib.rs @@ -15,6 +15,7 @@ mod borrow; mod error; mod guest_type; mod region; +pub mod tracing; pub use borrow::BorrowChecker; use borrow::BorrowHandle; diff --git a/crates/wiggle/src/tracing.rs b/crates/wiggle/src/tracing.rs new file mode 100644 index 0000000000..e9b5c6951d --- /dev/null +++ b/crates/wiggle/src/tracing.rs @@ -0,0 +1,11 @@ +#[cfg(feature = "tracing")] +pub use tracing_crate::*; + +#[cfg(not(feature = "tracing"))] +mod noop_tracing { + // TODO fill in rest of the noop interface + // idk how to do this because macro_rules! / #[macro_export] doesn't follow the usual module + // visibility rules. +} +#[cfg(not(feature = "tracing"))] +pub use noop_tracing::*; diff --git a/crates/wiggle/test-helpers/examples/tracing.rs b/crates/wiggle/test-helpers/examples/tracing.rs new file mode 100644 index 0000000000..d4f929689c --- /dev/null +++ b/crates/wiggle/test-helpers/examples/tracing.rs @@ -0,0 +1,118 @@ +use wiggle_test::{impl_errno, HostMemory, WasiCtx}; + +/// The `errors` argument to the wiggle gives us a hook to map a rich error +/// type like this one (typical of wiggle use cases in wasi-common and beyond) +/// down to the flat error enums that witx can specify. +#[derive(Debug, thiserror::Error)] +pub enum RichError { + #[error("Invalid argument: {0}")] + InvalidArg(String), + #[error("Won't cross picket line: {0}")] + PicketLine(String), +} + +// Define an errno with variants corresponding to RichError. Use it in a +// trivial function. +wiggle::from_witx!({ +witx_literal: " +(typename $errno (enum u8 $ok $invalid_arg $picket_line)) +(typename $s (struct (field $f1 (@witx usize)) (field $f2 (@witx pointer u8)))) +(typename $t (struct (field $f1 u32) (field $f2 f32))) +(module $one_error_conversion + (@interface func (export \"foo\") + (param $strike u32) + (param $s $s) + (result $err $errno) + (result $t $t))) + ", + ctx: WasiCtx, + errors: { errno => RichError }, +}); + +// The impl of GuestErrorConversion works just like in every other test where +// we have a single error type with witx `$errno` with the success called `$ok` +impl_errno!(types::Errno, types::GuestErrorConversion); + +/// When the `errors` mapping in witx is non-empty, we need to impl the +/// types::UserErrorConversion trait that wiggle generates from that mapping. +impl<'a> types::UserErrorConversion for WasiCtx<'a> { + fn errno_from_rich_error(&self, e: RichError) -> types::Errno { + wiggle::tracing::debug!( + rich_error = wiggle::tracing::field::debug(&e), + "error conversion" + ); + // WasiCtx can collect a Vec log so we can test this. We're + // logging the Display impl that `thiserror::Error` provides us. + self.log.borrow_mut().push(e.to_string()); + // Then do the trivial mapping down to the flat enum. + match e { + RichError::InvalidArg { .. } => types::Errno::InvalidArg, + RichError::PicketLine { .. } => types::Errno::PicketLine, + } + } +} + +impl<'a> one_error_conversion::OneErrorConversion for WasiCtx<'a> { + fn foo(&self, strike: u32, _s: &types::S) -> Result { + // We use the argument to this function to exercise all of the + // possible error cases we could hit here + match strike { + 0 => Ok(types::T { + f1: 123, + f2: 456.78, + }), + 1 => Err(RichError::PicketLine(format!("I'm not a scab"))), + _ => Err(RichError::InvalidArg(format!("out-of-bounds: {}", strike))), + } + } +} + +fn main() { + let subscriber = tracing_subscriber::fmt() + // all spans/events with a level higher than TRACE (e.g, debug, info, warn, etc.) + // will be written to stdout. + .with_max_level(tracing::Level::TRACE) + // builds the subscriber. + .finish(); + + tracing::subscriber::with_default(subscriber, || { + let ctx = WasiCtx::new(); + let host_memory = HostMemory::new(); + + // Exercise each of the branches in `foo`. + // Start with the success case: + let r0 = one_error_conversion::foo(&ctx, &host_memory, 0, 0, 8); + assert_eq!( + r0, + i32::from(types::Errno::Ok), + "Expected return value for strike=0" + ); + assert!(ctx.log.borrow().is_empty(), "No error log for strike=0"); + + // First error case: + let r1 = one_error_conversion::foo(&ctx, &host_memory, 1, 0, 8); + assert_eq!( + r1, + i32::from(types::Errno::PicketLine), + "Expected return value for strike=1" + ); + assert_eq!( + ctx.log.borrow_mut().pop().expect("one log entry"), + "Won't cross picket line: I'm not a scab", + "Expected log entry for strike=1", + ); + + // Second error case: + let r2 = one_error_conversion::foo(&ctx, &host_memory, 2, 0, 8); + assert_eq!( + r2, + i32::from(types::Errno::InvalidArg), + "Expected return value for strike=2" + ); + assert_eq!( + ctx.log.borrow_mut().pop().expect("one log entry"), + "Invalid argument: out-of-bounds: 2", + "Expected log entry for strike=2", + ); + }); +}