From dfef71ea5fa7a8098ad2ac03c1c5afa0178a0ef7 Mon Sep 17 00:00:00 2001 From: Alex Crichton Date: Fri, 7 Feb 2020 13:28:26 -0600 Subject: [PATCH] Add some debug logging to fuzzers (#923) * Add some debug logging to fuzzers This is useful when trying to figure out what happened locally when debugging fuzz test cases. By setting `RUST_LOG=wasmtime_fuzzing=debug` you can get wasm files written to disk and for the API calls test case see what API calls are being made. * Also write out `*.wat` files * rustfmt * Remove return value from `log_wasm` * Remove unused import --- crates/fuzzing/Cargo.toml | 4 +--- crates/fuzzing/src/oracles.rs | 34 ++++++++++++++++++++++++++++++++++ 2 files changed, 35 insertions(+), 3 deletions(-) diff --git a/crates/fuzzing/Cargo.toml b/crates/fuzzing/Cargo.toml index 9864ac8445..2ba90cd990 100644 --- a/crates/fuzzing/Cargo.toml +++ b/crates/fuzzing/Cargo.toml @@ -6,13 +6,11 @@ name = "wasmtime-fuzzing" publish = false version = "0.9.0" -# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html - [dependencies] anyhow = "1.0.22" arbitrary = { version = "0.3.2", features = ["derive"] } binaryen = "0.10.0" -env_logger = { version = "0.7.1", optional = true } +env_logger = "0.7.1" log = "0.4.8" wasmparser = "0.51.0" wasmprinter = "0.2.0" diff --git a/crates/fuzzing/src/oracles.rs b/crates/fuzzing/src/oracles.rs index a43c0a50c7..3af5ea8fa0 100644 --- a/crates/fuzzing/src/oracles.rs +++ b/crates/fuzzing/src/oracles.rs @@ -14,9 +14,11 @@ pub mod dummy; use dummy::{dummy_imports, dummy_values}; use std::collections::{HashMap, HashSet}; +use std::sync::atomic::{AtomicUsize, Ordering::SeqCst}; use wasmtime::*; fn fuzz_default_config(strategy: Strategy) -> Config { + drop(env_logger::try_init()); let mut config = Config::new(); config .cranelift_debug_verifier(true) @@ -26,6 +28,22 @@ fn fuzz_default_config(strategy: Strategy) -> Config { return config; } +fn log_wasm(wasm: &[u8]) { + static CNT: AtomicUsize = AtomicUsize::new(0); + if !log::log_enabled!(log::Level::Debug) { + return; + } + + let i = CNT.fetch_add(1, SeqCst); + let name = format!("testcase{}.wasm", i); + std::fs::write(&name, wasm).expect("failed to write wasm file"); + log::debug!("wrote wasm file to `{}`", name); + if let Ok(s) = wasmprinter::print_bytes(wasm) { + let name = format!("testcase{}.wat", i); + std::fs::write(&name, s).expect("failed to write wat file"); + } +} + /// Instantiate the Wasm buffer, and implicitly fail if we have an unexpected /// panic or segfault or anything else that can be detected "passively". /// @@ -46,6 +64,7 @@ pub fn instantiate_with_config(wasm: &[u8], config: Config) { let engine = Engine::new(&config); let store = Store::new(&engine); + log_wasm(wasm); let module = match Module::new(&store, wasm) { Ok(module) => module, Err(_) => return, @@ -77,6 +96,7 @@ pub fn instantiate_with_config(wasm: &[u8], config: Config) { pub fn compile(wasm: &[u8], strategy: Strategy) { let engine = Engine::new(&fuzz_default_config(strategy)); let store = Store::new(&engine); + log_wasm(wasm); let _ = Module::new(&store, wasm); } @@ -88,6 +108,7 @@ pub fn differential_execution( ttf: &crate::generators::WasmOptTtf, configs: &[crate::generators::DifferentialConfig], ) { + drop(env_logger::try_init()); // We need at least two configs. if configs.len() < 2 // And all the configs should be unique. @@ -104,6 +125,7 @@ pub fn differential_execution( }; let mut export_func_results: HashMap, Trap>> = Default::default(); + log_wasm(&ttf.wasm); for config in &configs { let engine = Engine::new(config); @@ -258,6 +280,8 @@ fn assert_same_export_func_result( pub fn make_api_calls(api: crate::generators::api::ApiCalls) { use crate::generators::api::ApiCall; + drop(env_logger::try_init()); + let mut config: Option = None; let mut engine: Option = None; let mut store: Option = None; @@ -267,6 +291,7 @@ pub fn make_api_calls(api: crate::generators::api::ApiCalls) { for call in api.calls { match call { ApiCall::ConfigNew => { + log::trace!("creating config"); assert!(config.is_none()); let mut cfg = Config::new(); cfg.cranelift_debug_verifier(true); @@ -274,20 +299,25 @@ pub fn make_api_calls(api: crate::generators::api::ApiCalls) { } ApiCall::ConfigDebugInfo(b) => { + log::trace!("enabling debuginfo"); config.as_mut().unwrap().debug_info(b); } ApiCall::EngineNew => { + log::trace!("creating engine"); assert!(engine.is_none()); engine = Some(Engine::new(config.as_ref().unwrap())); } ApiCall::StoreNew => { + log::trace!("creating store"); assert!(store.is_none()); store = Some(Store::new(engine.as_ref().unwrap())); } ApiCall::ModuleNew { id, wasm } => { + log::debug!("creating module: {}", id); + log_wasm(&wasm.wasm); let module = match Module::new(store.as_ref().unwrap(), &wasm.wasm) { Ok(m) => m, Err(_) => continue, @@ -297,10 +327,12 @@ pub fn make_api_calls(api: crate::generators::api::ApiCalls) { } ApiCall::ModuleDrop { id } => { + log::trace!("dropping module: {}", id); drop(modules.remove(&id)); } ApiCall::InstanceNew { id, module } => { + log::trace!("instantiating module {} as {}", module, id); let module = match modules.get(&module) { Some(m) => m, None => continue, @@ -326,10 +358,12 @@ pub fn make_api_calls(api: crate::generators::api::ApiCalls) { } ApiCall::InstanceDrop { id } => { + log::trace!("dropping instance {}", id); drop(instances.remove(&id)); } ApiCall::CallExportedFunc { instance, nth } => { + log::trace!("calling instance export {} / {}", instance, nth); let instance = match instances.get(&instance) { Some(i) => i, None => {