//! Optional standard [`log`] facade backed by single-attempt atomic ingresses. //! //! The ingress never allocates, masks interrupts, locks, spins, encodes //! MAVLink, or accesses DMA. Flight images keep this feature disabled; a //! future normal-task image must reject ISR/panic paths before formatting. use core::{ cell::UnsafeCell, sync::atomic::{AtomicBool, Ordering}, }; use log::{Level, LevelFilter, Log, Metadata, Record, SetLoggerError}; use crate::{ErrorAdditionalInformation, ErrorPath, LogFlags, LogRecord, LogText, Severity}; /// Saturating, process-local accounting for the optional global facade. /// /// It is deliberately not serialized in a Kaptan diagnostic message; the /// facade remains a small text ingress rather than a metrics protocol. #[derive(Clone, Copy, Debug, Default, Eq, PartialEq)] pub struct FacadeHealth { /// Calls rejected before formatting because their context is forbidden. pub forbidden_context: u32, /// Calls that lost the one-attempt ingress ownership race. pub contended: u32, /// Calls dropped because their bounded ingress lane was full. pub full: u32, /// Formatted messages truncated to the fixed text capacity. pub truncated: u32, } struct FacadeCounters { forbidden_context: core::sync::atomic::AtomicU32, contended: core::sync::atomic::AtomicU32, full: core::sync::atomic::AtomicU32, truncated: core::sync::atomic::AtomicU32, } impl FacadeCounters { const fn new() -> Self { Self { forbidden_context: core::sync::atomic::AtomicU32::new(0), contended: core::sync::atomic::AtomicU32::new(0), full: core::sync::atomic::AtomicU32::new(0), truncated: core::sync::atomic::AtomicU32::new(0), } } /// A single compare-exchange keeps this diagnostic counter non-wrapping /// without a retry loop. Under simultaneous facade callers it may /// undercount, but it never blocks or falsely wraps to zero. fn increment(counter: &core::sync::atomic::AtomicU32) { let current = counter.load(Ordering::Relaxed); if current != u32::MAX { let _ = counter.compare_exchange( current, current + 1, Ordering::Relaxed, Ordering::Relaxed, ); } } fn snapshot(&self) -> FacadeHealth { FacadeHealth { forbidden_context: self.forbidden_context.load(Ordering::Relaxed), contended: self.contended.load(Ordering::Relaxed), full: self.full.load(Ordering::Relaxed), truncated: self.truncated.load(Ordering::Relaxed), } } } #[derive(Clone, Copy)] struct IngressRecord { severity: Severity, flags: LogFlags, body: IngressBody, } #[derive(Clone, Copy)] enum IngressBody { Log { message: LogText, }, Error { path: ErrorPath, additional_information: ErrorAdditionalInformation, }, } impl IngressBody { const fn is_truncated(self) -> bool { match self { Self::Log { message } => message.is_truncated(), Self::Error { path, additional_information, } => path.is_truncated() || additional_information.is_truncated(), } } } struct IngressQueue { entries: [Option; N], head: usize, len: usize, } impl IngressQueue { const fn new() -> Self { assert!(N > 0, "facade ingress must be nonempty"); Self { entries: [None; N], head: 0, len: 0, } } fn push(&mut self, record: IngressRecord) -> bool { if self.len == N { return false; } let index = (self.head + self.len) % N; self.entries[index] = Some(record); self.len += 1; true } fn pop(&mut self) -> Option { if self.len == 0 { return None; } let record = self.entries[self.head].take(); self.head = (self.head + 1) % N; self.len -= 1; record } } /// Fixed global-facade ingress. The normal task/runtime owner takes each /// transport-neutral record and fans it out to independently filtered sinks. pub struct FacadeIngress { /// One dedicated critical slot keeps error records independent from the /// bounded ordinary FIFO. It is deliberately one slot: producers never /// spin, and a later error may be dropped only when an earlier error is /// already retained. critical: UnsafeCell>, critical_busy: AtomicBool, queue: UnsafeCell>, queue_busy: AtomicBool, counters: FacadeCounters, } // SAFETY: each interior-mutability cell is accessed only while its matching // atomic busy bit is acquired by one compare-exchange. The operation never // waits or retries; contention leaves the corresponding bounded lane intact. unsafe impl Sync for FacadeIngress {} impl FacadeIngress { /// Creates an empty fixed ingress. pub const fn new() -> Self { Self { critical: UnsafeCell::new(None), critical_busy: AtomicBool::new(false), queue: UnsafeCell::new(IngressQueue::new()), queue_busy: AtomicBool::new(false), counters: FacadeCounters::new(), } } fn push(&self, record: IngressRecord) { if record.severity <= Severity::Error { self.push_critical(record); return; } match self.with_queue(|queue| queue.push(record)) { Some(true) => {} Some(false) => FacadeCounters::increment(&self.counters.full), None => FacadeCounters::increment(&self.counters.contended), } } fn push_critical(&self, record: IngressRecord) { match self.with_critical(|slot| { if slot.is_none() { *slot = Some(record); true } else { false } }) { Some(true) => {} Some(false) => FacadeCounters::increment(&self.counters.full), None => FacadeCounters::increment(&self.counters.contended), } } /// Process-local bounded-ingress accounting. pub fn health(&self) -> FacadeHealth { self.counters.snapshot() } /// Takes at most one preformatted event for composition-level fan-out. /// /// The ingress deliberately applies no sink policy. A caller may submit /// the returned copy to MAVLink, blackbox, or any later sink without one /// sink's verbosity selection suppressing another's event. pub fn take(&self) -> Option { let record = match self.with_critical(Option::take) { Some(Some(record)) => record, Some(None) => self.with_queue(IngressQueue::pop).flatten()?, None => return None, }; Some(match record.body { IngressBody::Log { message } => LogRecord::new(record.severity, record.flags, message), IngressBody::Error { path, additional_information, } => LogRecord::error(record.flags, path, additional_information), }) } fn with_critical( &self, operation: impl FnOnce(&mut Option) -> R, ) -> Option { if self .critical_busy .compare_exchange(false, true, Ordering::Acquire, Ordering::Relaxed) .is_err() { return None; } // SAFETY: `critical_busy` grants exclusive access to the one fixed // critical slot. No call to `operation` escapes its mutable reference. let result = operation(unsafe { &mut *self.critical.get() }); self.critical_busy.store(false, Ordering::Release); Some(result) } fn with_queue(&self, operation: impl FnOnce(&mut IngressQueue) -> R) -> Option { if self .queue_busy .compare_exchange(false, true, Ordering::Acquire, Ordering::Relaxed) .is_err() { return None; } // SAFETY: `queue_busy` grants this caller exclusive access. No call // to `operation` escapes the mutable reference and it only performs // fixed-array queue work. let result = operation(unsafe { &mut *self.queue.get() }); self.queue_busy.store(false, Ordering::Release); Some(result) } } impl Default for FacadeIngress { fn default() -> Self { Self::new() } } /// Installed standard logger. The context probe must return true for /// ISR/panic/hard-fault/shutdown contexts; those calls are rejected before /// [`Record::args`] is formatted. pub struct GlobalLogger { ingress: &'static FacadeIngress, forbidden_context: fn() -> bool, } impl GlobalLogger { /// Creates a logger tied to one static bounded ingress. pub const fn new(ingress: &'static FacadeIngress, forbidden_context: fn() -> bool) -> Self { Self { ingress, forbidden_context, } } /// Installs this logger once for the process/image and enables all Rust /// levels compiled into the image. Each sink applies its policy after it /// receives a record from the ingress. pub fn install(&'static self) -> Result<(), SetLoggerError> { log::set_logger(self)?; log::set_max_level(LevelFilter::Trace); Ok(()) } } impl Log for GlobalLogger { fn enabled(&self, _: &Metadata<'_>) -> bool { if (self.forbidden_context)() { FacadeCounters::increment(&self.ingress.counters.forbidden_context); return false; } true } fn log(&self, record: &Record<'_>) { if (self.forbidden_context)() { FacadeCounters::increment(&self.ingress.counters.forbidden_context); return; } let severity = severity(record.level()); let flags = if record.level() == Level::Trace { LogFlags::TRACE } else { LogFlags::NONE }; let body = if severity <= Severity::Error { IngressBody::Error { path: ErrorPath::from_message(record.target()), additional_information: ErrorAdditionalInformation::from_arguments(format_args!( "{}", record.args() )), } } else { IngressBody::Log { message: LogText::from_arguments(format_args!( "[{}] {}", record.target(), record.args() )), } }; if body.is_truncated() { FacadeCounters::increment(&self.ingress.counters.truncated); } self.ingress.push(IngressRecord { severity, flags, body, }); } fn flush(&self) {} } const fn severity(level: Level) -> Severity { match level { Level::Error => Severity::Error, Level::Warn => Severity::Warning, Level::Info => Severity::Info, Level::Debug | Level::Trace => Severity::Debug, } } #[cfg(test)] mod tests { use core::fmt; use std::sync::Once; use super::{FacadeIngress, GlobalLogger}; use crate::{RecordChannel, Severity}; use log::{Level, Log, Metadata, Record}; static GLOBAL_INGRESS: FacadeIngress<2> = FacadeIngress::new(); static GLOBAL_LOGGER: GlobalLogger<2> = GlobalLogger::new(&GLOBAL_INGRESS, never_forbidden); static INSTALL_GLOBAL: Once = Once::new(); fn never_forbidden() -> bool { false } fn always_forbidden() -> bool { true } #[test] fn rejects_forbidden_context_before_formatting() { static INGRESS: FacadeIngress<2> = FacadeIngress::new(); let logger = GlobalLogger::new(&INGRESS, always_forbidden); let metadata = Metadata::builder() .level(Level::Error) .target("test") .build(); assert!(!logger.enabled(&metadata)); assert_eq!(INGRESS.health().forbidden_context, 1); static UNFILTERED: FacadeIngress<2> = FacadeIngress::new(); let unfiltered_logger = GlobalLogger::new(&UNFILTERED, never_forbidden); let debug = Metadata::builder() .level(Level::Debug) .target("test") .build(); assert!(unfiltered_logger.enabled(&debug)); unfiltered_logger.log( &Record::builder() .metadata(debug) .args(format_args!("sink decides whether to keep this")) .build(), ); assert_eq!( UNFILTERED .take() .expect("debug event reaches the unfiltered ingress") .severity(), Severity::Debug ); } #[test] fn formats_once_then_exposes_a_transport_neutral_record() { static INGRESS: FacadeIngress<2> = FacadeIngress::new(); let logger = GlobalLogger::new(&INGRESS, never_forbidden); let record = Record::builder() .metadata( Metadata::builder() .level(Level::Error) .target("test") .build(), ) .args(format_args!("link failed")) .build(); logger.log(&record); let pending = INGRESS.take().expect("facade event retained"); assert_eq!(pending.error_path().unwrap().as_str(), "test"); assert_eq!( pending.additional_information().unwrap().as_str(), "link failed" ); assert_eq!(pending.severity(), Severity::Error); assert_eq!(pending.channel(), RecordChannel::Error); } struct MustNotFormat; impl fmt::Display for MustNotFormat { fn fmt(&self, _: &mut fmt::Formatter<'_>) -> fmt::Result { panic!("forbidden-context log arguments must not format") } } #[test] fn standard_log_macros_enqueue_bounded_targeted_text() { INSTALL_GLOBAL.call_once(|| GLOBAL_LOGGER.install().expect("one global test logger")); log::info!("armed configuration loaded"); assert!( GLOBAL_INGRESS .take() .expect("macro event retained") .message() .unwrap() .as_str() .ends_with("armed configuration loaded") ); } #[test] fn forbidden_context_skips_argument_formatting() { static INGRESS: FacadeIngress<2> = FacadeIngress::new(); let logger = GlobalLogger::new(&INGRESS, always_forbidden); logger.log( &Record::builder() .metadata( Metadata::builder() .level(Level::Error) .target("test") .build(), ) .args(format_args!("{}", MustNotFormat)) .build(), ); assert_eq!(INGRESS.health().forbidden_context, 1); } #[test] fn bounded_ingress_exposes_local_drop_and_truncation_accounting() { static INGRESS: FacadeIngress<1> = FacadeIngress::new(); let logger = GlobalLogger::new(&INGRESS, never_forbidden); logger.log( &Record::builder() .metadata( Metadata::builder() .level(Level::Info) .target("test") .build(), ) .args(format_args!("x")) .build(), ); logger.log( &Record::builder() .metadata( Metadata::builder() .level(Level::Info) .target("test") .build(), ) .args(format_args!("y")) .build(), ); let long = "z".repeat(crate::MAXIMUM_LOG_TEXT_BYTES + 1); logger.log( &Record::builder() .metadata( Metadata::builder() .level(Level::Info) .target("test") .build(), ) .args(format_args!("{long}")) .build(), ); let health = INGRESS.health(); assert_eq!(health.full, 2); assert_eq!(health.truncated, 1); } #[test] fn full_optional_ingress_retains_an_error_for_the_error_channel() { static INGRESS: FacadeIngress<1> = FacadeIngress::new(); let logger = GlobalLogger::new(&INGRESS, never_forbidden); logger.log( &Record::builder() .metadata( Metadata::builder() .level(Level::Info) .target("test") .build(), ) .args(format_args!("optional")) .build(), ); logger.log( &Record::builder() .metadata( Metadata::builder() .level(Level::Error) .target("test") .build(), ) .args(format_args!("critical")) .build(), ); let error = INGRESS .take() .expect("error retained ahead of optional text"); assert_eq!(error.channel(), RecordChannel::Error); assert_eq!(error.error_path().unwrap().as_str(), "test"); assert_eq!(error.additional_information().unwrap().as_str(), "critical"); assert_eq!(INGRESS.health().full, 0); } }