diff --git a/dev_bench/src/main.rs b/dev_bench/src/main.rs index 23168af5c..3ab56fe63 100644 --- a/dev_bench/src/main.rs +++ b/dev_bench/src/main.rs @@ -107,6 +107,12 @@ fn main() -> Result<()> { _ => tracing::Level::TRACE, }) .init(); + if cli_args.lock_tracing && std::env::var_os("LITEBOX_LOG").is_none() { + warn!("--lock-tracing is enabled but LITEBOX_LOG is not set"); + warn!(" lock trace output will not be visible"); + warn!(" set e.g. LITEBOX_LOG=trace to see lock tracing output"); + warn!(" also confirm the CONFIG_PRINT_* booleans in lock_tracing.rs are enabled"); + } if cli_args.verbose > 2 { warn!( verbosity = cli_args.verbose, diff --git a/litebox/src/sync/lock_tracing.rs b/litebox/src/sync/lock_tracing.rs index a7e03bc96..c7b4abf7f 100644 --- a/litebox/src/sync/lock_tracing.rs +++ b/litebox/src/sync/lock_tracing.rs @@ -32,7 +32,7 @@ use core::time::Duration; -use arrayvec::{ArrayString, ArrayVec}; +use arrayvec::ArrayVec; use crate::platform::Instant as _; @@ -477,21 +477,16 @@ struct LockTrackerX { /// lock tracking. This is necessary so that `LOCK_TRACKER` can be a singleton /// (no generics allowed in statics). The backing platform traits are not /// dyn-compatible. +// XXX(jb): Now, after the move away from DebugLogProvider, can we remove this? trait DynLockTrackerProvider: Send + Sync { /// Gets the current time, relative to some unspecified epoch. fn now(&self) -> Duration; - /// Print a debug log message. - fn debug_log_print(&self, msg: &str); } impl DynLockTrackerProvider for LockTrackerPlatform { fn now(&self) -> Duration { self.platform.now().duration_since(&self.start_time) } - - fn debug_log_print(&self, msg: &str) { - self.platform.debug_log_print(msg); - } } impl LockTracker { @@ -584,20 +579,6 @@ pub(crate) struct LockAttemptWitness { tracker: &'static LockTracker, } -// A `println!` style macro that uses `debug_log_print` but gives a nicer interface. -// -// NOTE: If the print ever deadlocks/hangs, that means that there might be allocation being done by -// the call, because it is longer than the size of the `SmallString`. Just bump up the number inside -// the `SmallString` array below to 2x the value. -macro_rules! debug_log_println { - ($platform:expr, $($tt:tt)*) => {{ - use core::fmt::Write; - let mut t: ArrayString<1024> = ArrayString::new(); - writeln!(t, $($tt)*).unwrap(); - $platform.debug_log_print(&t); - }} -} - impl LockTracker { /// Mark the `lock_type` (at `lock_addr`) as being attempted to be locked. It is the caller's /// job to make sure `#[track_caller]` is inserted, and that things are kept in sync with the @@ -625,6 +606,13 @@ impl LockTracker { } } +/// Visual indentation for lock depth in log output. The `!` is to indicate that we've gone further +/// than we should +fn depth_dots(n: usize) -> &'static str { + const DOTS: &str = ".............................................................!"; + &DOTS[..n.min(DOTS.len())] +} + impl LockTrackerX { /// Access this via [`LockTracker::begin_lock_attempt`] #[must_use] @@ -660,28 +648,30 @@ impl LockTrackerX { }; if CONFIG_PRINT_LOCK_ATTEMPTS { if let Some(t) = contended { - debug_log_println!( - tracker.as_ref().unwrap().platform, - "[LOCKTRACER{blank:. max_allowed { if let Some(contended) = contended_with { - debug_log_println!( - tracker.platform, - "[LOCKTRACER{blank:. RawSyncPrimitivesProvider for Platform where #[cfg(feature = "lock_tracing")] /// A convenience name for specific requirements from the platform pub trait RawSyncPrimitivesProvider: - platform::RawMutexProvider + platform::TimeProvider + platform::DebugLogProvider + Sync + 'static + platform::RawMutexProvider + platform::TimeProvider + Sync + 'static { } #[cfg(feature = "lock_tracing")] impl RawSyncPrimitivesProvider for Platform where - Platform: platform::RawMutexProvider - + platform::TimeProvider - + platform::DebugLogProvider - + Sync - + 'static + Platform: platform::RawMutexProvider + platform::TimeProvider + Sync + 'static { }