diff --git a/benches/benchmarks.rs b/benches/benchmarks.rs new file mode 100644 index 000000000..81cfe484a --- /dev/null +++ b/benches/benchmarks.rs @@ -0,0 +1,96 @@ +#![feature(test)] + +extern crate test; + +extern crate backtrace; + +#[cfg(feature = "std")] +use backtrace::Backtrace; + +#[bench] +#[cfg(feature = "std")] +fn trace(b: &mut test::Bencher) { + #[inline(never)] + fn the_function() { + backtrace::trace(|frame| { + let ip = frame.ip(); + test::black_box(ip); + true + }); + } + b.iter(the_function); +} + +#[bench] +#[cfg(feature = "std")] +fn trace_and_resolve_callback(b: &mut test::Bencher) { + #[inline(never)] + fn the_function() { + backtrace::trace(|frame| { + backtrace::resolve(frame.ip(), |symbol| { + let addr = symbol.addr(); + test::black_box(addr); + }); + true + }); + } + b.iter(the_function); +} + + + +#[bench] +#[cfg(feature = "std")] +fn trace_and_resolve_separate(b: &mut test::Bencher) { + #[inline(never)] + fn the_function(frames: &mut Vec<*mut std::ffi::c_void>) { + backtrace::trace(|frame| { + frames.push(frame.ip()); + true + }); + frames.iter().for_each(|frame_ip| { + backtrace::resolve(*frame_ip, |symbol| { + test::black_box(symbol); + }); + }); + } + let mut frames = Vec::with_capacity(1024); + b.iter(|| { + the_function(&mut frames); + frames.clear(); + }); +} + +#[bench] +#[cfg(feature = "std")] +fn new_unresolved(b: &mut test::Bencher) { + #[inline(never)] + fn the_function() { + let bt = Backtrace::new_unresolved(); + test::black_box(bt); + } + b.iter(the_function); +} + +#[bench] +#[cfg(feature = "std")] +fn new(b: &mut test::Bencher) { + #[inline(never)] + fn the_function() { + let bt = Backtrace::new(); + test::black_box(bt); + } + b.iter(the_function); +} + +#[bench] +#[cfg(feature = "std")] +fn new_unresolved_and_resolve_separate(b: &mut test::Bencher) { + #[inline(never)] + fn the_function() { + let mut bt = Backtrace::new_unresolved(); + bt.resolve(); + test::black_box(bt); + } + b.iter(the_function); +} \ No newline at end of file diff --git a/src/backtrace/dbghelp.rs b/src/backtrace/dbghelp.rs index 12d5b374c..f09189e01 100644 --- a/src/backtrace/dbghelp.rs +++ b/src/backtrace/dbghelp.rs @@ -51,8 +51,11 @@ pub unsafe fn trace(cb: &mut FnMut(&super::Frame) -> bool) { }; let image = init_frame(&mut frame.inner.inner, &context.0); - // Initialize this process's symbols - let _c = ::dbghelp_init(); + // Ensure this process's symbols are initialized + let _cleanup = match ::dbghelp::init() { + Ok(cleanup) => cleanup, + Err(()) => return, // oh well... + }; // And now that we're done with all the setup, do the stack walking! while dbghelp::StackWalk64(image as DWORD, diff --git a/src/capture.rs b/src/capture.rs index bb180883e..4a35f7d2c 100644 --- a/src/capture.rs +++ b/src/capture.rs @@ -68,6 +68,7 @@ impl Backtrace { /// ``` #[inline(never)] // want to make sure there's a frame here to remove pub fn new() -> Backtrace { + let _guard = lock_and_platform_init(); let mut bt = Self::create(Self::new as usize); bt.resolve(); bt @@ -93,6 +94,7 @@ impl Backtrace { /// ``` #[inline(never)] // want to make sure there's a frame here to remove pub fn new_unresolved() -> Backtrace { + let _guard = lock_and_platform_init(); Self::create(Self::new_unresolved as usize) } @@ -141,6 +143,7 @@ impl Backtrace { /// If this backtrace has been previously resolved or was created through /// `new`, this function does nothing. pub fn resolve(&mut self) { + let _guard = lock_and_platform_init(); for frame in self.frames.iter_mut().filter(|f| f.symbols.is_none()) { let mut symbols = Vec::new(); resolve(frame.ip as *mut _, |symbol| { @@ -289,3 +292,48 @@ impl Default for Backtrace { Backtrace::new() } } + +// When using `dbghelp` on Windows this is a performance optimization. If +// we don't do this then `SymInitializeW` is called once per trace and once per +// frame during resolution. That function, however, takes quite some time! To +// help speed it up this function can amortize the calls necessary by ensuring +// that the scope this is called in only initializes when this is called and +// doesn't reinitialize for the rest of the scope. +#[cfg(all(windows, feature = "dbghelp"))] +fn lock_and_platform_init() -> impl Drop { + use std::mem::ManuallyDrop; + + struct Cleanup { + _lock: crate::lock::LockGuard, + + // Need to make sure this is cleaned up before `_lock` + dbghelp_cleanup: Option>, + } + + impl Drop for Cleanup { + fn drop(&mut self) { + if let Some(cleanup) = self.dbghelp_cleanup.as_mut() { + // Unsafety here should be ok since we're only dropping this in + // `Drop` to ensure it's dropped before the lock, and `Drop` + // should only be called once. + unsafe { + ManuallyDrop::drop(cleanup); + } + } + } + } + + // Unsafety here should be ok because we only acquire the `dbghelp` + // initialization (the unsafe part) after acquiring the global lock for this + // crate. Note that we're also careful to drop it before the lock is + // dropped. + unsafe { + Cleanup { + _lock: crate::lock::lock(), + dbghelp_cleanup: crate::dbghelp::init().ok().map(ManuallyDrop::new), + } + } +} + +#[cfg(not(all(windows, feature = "dbghelp")))] +fn lock_and_platform_init() {} diff --git a/src/lib.rs b/src/lib.rs index f988de8f6..96af909c7 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -148,7 +148,7 @@ mod lock { use std::boxed::Box; use std::sync::{Once, Mutex, MutexGuard, ONCE_INIT}; - pub struct LockGuard(MutexGuard<'static, ()>); + pub struct LockGuard(Option>); static mut LOCK: *mut Mutex<()> = 0 as *mut _; static INIT: Once = ONCE_INIT; @@ -156,39 +156,100 @@ mod lock { impl Drop for LockGuard { fn drop(&mut self) { - LOCK_HELD.with(|slot| { - assert!(slot.get()); - slot.set(false); - }); + if self.0.is_some() { + LOCK_HELD.with(|slot| { + assert!(slot.get()); + slot.set(false); + }); + } } } - pub fn lock() -> Option { + pub fn lock() -> LockGuard { if LOCK_HELD.with(|l| l.get()) { - return None + return LockGuard(None) } LOCK_HELD.with(|s| s.set(true)); unsafe { INIT.call_once(|| { LOCK = Box::into_raw(Box::new(Mutex::new(()))); }); - Some(LockGuard((*LOCK).lock().unwrap())) + LockGuard(Some((*LOCK).lock().unwrap())) } } } -// requires external synchronization #[cfg(all(windows, feature = "dbghelp"))] -unsafe fn dbghelp_init() { - use winapi::shared::minwindef; - use winapi::um::{dbghelp, processthreadsapi}; +mod dbghelp { + use core::ptr; + use winapi::shared::minwindef::{DWORD, TRUE}; + use winapi::um::processthreadsapi::GetCurrentProcess; + use winapi::um::dbghelp; + + pub struct Cleanup; + + static mut COUNT: usize = 0; + static mut OPTS_ORIG: DWORD = 0; - static mut INITIALIZED: bool = false; + const SYMOPT_DEFERRED_LOADS: DWORD = 0x00000004; + extern "system" { + fn SymGetOptions() -> DWORD; + fn SymSetOptions(options: DWORD); + } + + /// Unsafe because this requires external synchronization, must be done + /// inside of the same lock as all other backtrace operations. + /// + /// Note that the `Cleanup` returned must also be dropped within the same + /// lock. + #[cfg(all(windows, feature = "dbghelp"))] + pub unsafe fn init() -> Result { + // Initializing symbols has significant overhead, but initializing only + // once without cleanup causes problems for external sources. For + // example, the standard library checks the result of SymInitializeW + // (which returns an error if attempting to initialize twice) and in + // the event of an error, will not print a backtrace on panic. + // Presumably, external debuggers may have similar issues. + // + // As a compromise, we'll keep track of the number of internal + // initialization requests within a single API call in order to + // minimize the number of init/cleanup cycles. + + if COUNT > 0 { + COUNT += 1; + return Ok(Cleanup); + } - if !INITIALIZED { - dbghelp::SymInitializeW(processthreadsapi::GetCurrentProcess(), - 0 as *mut _, - minwindef::TRUE); - INITIALIZED = true; + OPTS_ORIG = SymGetOptions(); + + // Ensure that the `SYMOPT_DEFERRED_LOADS` flag is set, because + // according to MSVC's own docs about this: "This is the fastest, most + // efficient way to use the symbol handler.", so let's do that! + SymSetOptions(OPTS_ORIG | SYMOPT_DEFERRED_LOADS); + + let ret = dbghelp::SymInitializeW(GetCurrentProcess(), ptr::null_mut(), TRUE); + if ret != TRUE { + // Symbols may have been initialized by another library or an + // external debugger + SymSetOptions(OPTS_ORIG); + Err(()) + } else { + COUNT += 1; + Ok(Cleanup) + } + } + + impl Drop for Cleanup { + fn drop(&mut self) { + unsafe { + COUNT -= 1; + if COUNT != 0 { + return; + } + + dbghelp::SymCleanup(GetCurrentProcess()); + SymSetOptions(OPTS_ORIG); + } + } } } diff --git a/src/symbolize/dbghelp.rs b/src/symbolize/dbghelp.rs index abc89868a..233079c32 100644 --- a/src/symbolize/dbghelp.rs +++ b/src/symbolize/dbghelp.rs @@ -86,7 +86,11 @@ pub unsafe fn resolve(addr: *mut c_void, cb: &mut FnMut(&super::Symbol)) { // due to struct alignment. info.SizeOfStruct = 88; - let _c = ::dbghelp_init(); + // Ensure this process's symbols are initialized + let _cleanup = match ::dbghelp::init() { + Ok(cleanup) => cleanup, + Err(()) => return, // oh well... + }; let mut displacement = 0u64; let ret = dbghelp::SymFromAddrW(processthreadsapi::GetCurrentProcess(), diff --git a/tests/long_fn_name.rs b/tests/long_fn_name.rs index 862b62e70..8b53dabe1 100644 --- a/tests/long_fn_name.rs +++ b/tests/long_fn_name.rs @@ -23,7 +23,6 @@ mod _234567890_234567890_234567890_234567890_234567890 { #[test] #[cfg(all(windows, feature = "dbghelp", target_env = "msvc"))] fn test_long_fn_name() { - use winapi::um::dbghelp; use _234567890_234567890_234567890_234567890_234567890:: _234567890_234567890_234567890_234567890_234567890 as S;