From 3b0291b4f55be4fa7ff74b808abde98c08b9cae3 Mon Sep 17 00:00:00 2001 From: Robbert van der Helm Date: Sun, 24 Apr 2022 15:03:27 +0200 Subject: [PATCH] Add function for setting up file and windbg logs And also writing panics to those logs. --- Cargo.lock | 60 +++++++++++++++++++++++++++++++++ Cargo.toml | 8 +++++ src/wrapper/util.rs | 82 +++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 150 insertions(+) diff --git a/Cargo.lock b/Cargo.lock index 352f8e2e..4712cfb0 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1813,6 +1813,15 @@ dependencies = [ "value-bag", ] +[[package]] +name = "log-panics" +version = "2.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ae0136257df209261daa18d6c16394757c63e032e27aafd8b07788b051082bef" +dependencies = [ + "log", +] + [[package]] name = "lru" version = "0.7.5" @@ -2005,14 +2014,18 @@ dependencies = [ "crossbeam", "lazy_static", "libc", + "log", + "log-panics", "midi-consts", "nih_plug_derive", "parking_lot 0.12.0", "raw-window-handle", "serde", "serde_json", + "simplelog", "vst3-sys", "widestring", + "win_dbg_logger", "windows", ] @@ -2176,6 +2189,15 @@ dependencies = [ "libc", ] +[[package]] +name = "num_threads" +version = "0.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "aba1801fb138d8e85e11d0fc70baf4fe1cdfffda7c6cd34a854905df588e5ed0" +dependencies = [ + "libc", +] + [[package]] name = "objc" version = "0.2.7" @@ -3019,6 +3041,17 @@ dependencies = [ "log", ] +[[package]] +name = "simplelog" +version = "0.12.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "48dfff04aade74dd495b007c831cd6f4e0cee19c344dd9dc0884c0289b70a786" +dependencies = [ + "log", + "termcolor", + "time", +] + [[package]] name = "sine" version = "0.1.0" @@ -3223,6 +3256,24 @@ dependencies = [ "syn", ] +[[package]] +name = "time" +version = "0.3.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c2702e08a7a860f005826c6815dcac101b19b5eb330c27fe4a5928fec1d20ddd" +dependencies = [ + "itoa 1.0.1", + "libc", + "num_threads", + "time-macros", +] + +[[package]] +name = "time-macros" +version = "0.2.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "42657b1a6f4d817cda8e7a0ace261fe0cc946cf3a80314390b22cc61ae080792" + [[package]] name = "tiny-skia" version = "0.6.3" @@ -3853,6 +3904,15 @@ version = "1.0.0-beta.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "e6f1efe828a707edf85994a4501734ac1c1b9d244cfcf4de235f11c4125ace8f" +[[package]] +name = "win_dbg_logger" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7d1b4c22244dc27534d81e2f6fc3efd6b20e50c010f177efc20b719ec759a779" +dependencies = [ + "log", +] + [[package]] name = "winapi" version = "0.3.9" diff --git a/Cargo.toml b/Cargo.toml index b2fa54a3..744e7364 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -60,11 +60,14 @@ cfg-if = "1.0" clap-sys = { git = "https://github.com/robbert-vdh/clap-sys", branch = "update/clap-0.24" } crossbeam = "0.8" lazy_static = "1.4" +log = { version = "0.4", features = ["std", "release_max_level_info"] } +log-panics = "2.0" midi-consts = "0.1" parking_lot = "0.12" raw-window-handle = "0.4" serde = { version = "1.0", features = ["derive"] } serde_json = "1.0" +simplelog = "0.12" vst3-sys = { git = "https://github.com/robbert-vdh/vst3-sys.git", branch = "fix/note-off-event", optional = true } widestring = "1.0.0-beta.1" @@ -73,6 +76,11 @@ assert_no_alloc = { version = "1.1", optional = true } [target.'cfg(all(target_family = "unix", not(target_os = "macos")))'.dependencies] libc = "0.2.124" +[target.'cfg(target_os = "windows")'.dependencies] +# STDIO isn't reliable on Windows, so when hosting plugins in a DAW it may be +# useful to log using `OutputDebugString()` instead +win_dbg_logger = "0.1" + [target.'cfg(target_os = "windows")'.dependencies.windows] version = "0.32" features = [ diff --git a/src/wrapper/util.rs b/src/wrapper/util.rs index 0e76dcfc..dbc28324 100644 --- a/src/wrapper/util.rs +++ b/src/wrapper/util.rs @@ -1,6 +1,11 @@ use std::cmp; +use std::fs::File; use std::marker::PhantomData; use std::os::raw::c_char; +use std::sync::atomic::{AtomicBool, Ordering}; + +/// The environment variable for controlling the logging behavior. +const NIH_LOG_ENV: &str = "NIH_LOG"; #[cfg(all(debug_assertions, feature = "assert_process_allocs"))] #[global_allocator] @@ -39,6 +44,83 @@ pub fn strlcpy(dest: &mut [c_char], src: &str) { dest[copy_len] = 0; } +/// Set up the logger so that the `nih_*!()` logging and assertion macros log output to a +/// centralized location and panics also get written there. By default this logs to STDERR unless +/// the user is running Windows and a debugger has been attached, in which case +/// `OutputDebugString()` will be used instead. +/// +/// The logger's behavior can be controlled by setting the `NIH_LOG` environment variable to: +/// +/// - `stderr`, in which case the log output always gets written to STDERR. +/// - `windbg` (only on Windows), in which case the output always gets logged using +/// `OutputDebugString()`. +/// - A file path, in which case the output gets appended to the end of that file which will be +/// created if necessary. +/// +/// # TODO +/// +/// Document `NIH_LOG` in an easier to find place. +pub fn setup_logger() { + // `win_dbg_logger` has no way to let us know that the logger has already been set up, so we'll + // need to do it this way + static LOGGER_SET_UP: AtomicBool = AtomicBool::new(false); + if LOGGER_SET_UP + .compare_exchange(false, true, Ordering::SeqCst, Ordering::SeqCst) + .is_err() + { + return; + } + + let nih_log_env = std::env::var(NIH_LOG_ENV); + let nih_log_env_str = nih_log_env.as_deref().unwrap_or(""); + + #[cfg(target_os = "windows")] + if nih_log_env_str.eq_ignore_ascii_case("windbg") || win_dbg_logger::is_debugger_present() { + win_dbg_logger::init(); + log_panics::init(); + return; + } + + // If opening the file fails, then we'll log to STDERR anyways, hence this closure + let logger_config = simplelog::ConfigBuilder::new() + .set_thread_mode(simplelog::ThreadLogMode::Both) + .build(); + let init_stderr_logger = || { + simplelog::TermLogger::init( + simplelog::LevelFilter::Trace, + logger_config.clone(), + simplelog::TerminalMode::Stderr, + simplelog::ColorChoice::Auto, + ) + }; + + // If the logger has already been set up outside of this function then that won't cause any + // problems, so we can ignore the results here + if nih_log_env_str.eq_ignore_ascii_case("stderr") || nih_log_env_str.is_empty() { + let _ = init_stderr_logger(); + } else { + let file = File::options() + .append(true) + .create(true) + .open(nih_log_env_str); + match file { + Ok(file) => { + let _ = simplelog::WriteLogger::init( + simplelog::LevelFilter::Trace, + logger_config, + file, + ); + } + Err(err) => { + let _ = init_stderr_logger(); + nih_debug_assert_failure!("Could not open '{}': {:?}", nih_log_env_str, err); + } + } + } + + log_panics::init(); +} + /// A wrapper around the entire process function, including the plugin wrapper parts. This sets up /// `assert_no_alloc` if needed, while also making sure that things like FTZ are set up correctly if /// the host has not already done so.