nros_log/lib.rs
1//! Phase 88 — portable leveled-logging facade for nano-ros.
2//!
3//! See [`docs/roadmap/archived/phase-88-nros-log.md`](../../../docs/roadmap/archived/phase-88-nros-log.md)
4//! for the design and acceptance criteria.
5//!
6//! ## Layering
7//!
8//! - This crate carries only the portable types + dispatcher +
9//! macros + `PlatformSink`. No backend code.
10//! - Per-platform log delivery is the responsibility of each
11//! `nros-platform-<rtos>` crate, exposing
12//! `nros_platform_log_write` / `nros_platform_log_flush` via the
13//! `nros_platform_*` ABI (header at
14//! `packages/platform/nros-platform-api/include/nros/platform.h`).
15//! - `PlatformSink` is the bridge: a single `LogSink` impl that
16//! forwards to the ABI. Apps that want fan-out (e.g.
17//! `Platform + /rosout`) compose a `&'static [&dyn LogSink]`
18//! manually and pass it to [`init`].
19//!
20//! ## Quick start
21//!
22//! ```ignore
23//! use nros_log::{Logger, Severity};
24//! use nros_log::{log_info, log_warn};
25//!
26//! static LOGGER: Logger = Logger::new("my_node");
27//!
28//! fn main() {
29//! nros_log::register_logger(&LOGGER);
30//! nros_log::init(nros_log::sinks::default());
31//! log_info!(&LOGGER, "started; domain = {}", 42);
32//! }
33//! ```
34
35// UNCONDITIONAL. This was `cfg_attr(not(feature = "std"), no_std)`, which
36// bought nothing: this crate's `std` feature is `std = ["alloc"]` over
37// `alloc = []`, so it enables no std functionality and the crate uses none.
38// The conditional form only meant that building with `std` compiled a
39// DIFFERENT crate -- a second configuration nobody wanted and no lane checked.
40//
41// ARCHITECTURE section 2 / phase-359: the terminal state of a core crate is
42// `core` or `core+alloc`. `check-core-crates-are-no-std` holds every core
43// crate to this spelling.
44#![no_std]
45#![deny(unsafe_op_in_unsafe_fn)]
46#![warn(missing_docs)]
47
48#[cfg(feature = "alloc")]
49extern crate alloc;
50
51// Phase 88.16.E — portable-atomic polyfill for CAS-less targets
52// (RISC-V `imc`, etc.). Feature unification: a consuming bare-metal
53// crate enables `unsafe-assume-single-core` / `critical-section` on
54// its own `portable-atomic` dep; native CAS targets get the
55// passthrough.
56use portable_atomic::{AtomicBool, AtomicPtr, AtomicU8, AtomicUsize, Ordering};
57
58pub mod early;
59#[cfg(feature = "log-compat")]
60pub mod log_compat;
61pub mod log_params;
62pub mod macros;
63pub mod pool;
64#[cfg(feature = "rosout")]
65pub mod rosout;
66pub mod sinks;
67pub mod throttle;
68
69mod buffer;
70
71/// The resolved `[knobs.log]` tenant, written by `build.rs` (phase-479 W5,
72/// issue 1037). One file, one place each value enters the crate.
73mod config {
74 include!(concat!(env!("OUT_DIR"), "/nros_log_config.rs"));
75
76 // `build.rs` range-checks the knob; this keeps a hand-edited or stale
77 // file from compiling into a ceiling above `off`.
78 #[allow(clippy::absurd_extreme_comparisons)]
79 const _: () = assert!(MAX_LEVEL <= 6, "NROS_LOG_MAX_LEVEL is 0..=6");
80}
81
82pub use buffer::{FormatBuffer, format_buffer_capacity};
83pub use log_params::{LogOccurrence, LogParams, ThrottleClock, ToLogParams};
84pub use pool::{
85 MAX_LOGGER_NAME_LEN, dynamic_logger_capacity, dynamic_logger_name_arena, dynamic_loggers_in_use,
86};
87pub use throttle::{ThrottleState, interval_ms_to_ns, throttle_decide};
88
89/// REP-2012 severity levels: rcutils's five, in rcutils's order, plus `Trace`.
90///
91/// NOT `rcutils_log_severity_t`'s numbering (`UNSET=0, DEBUG=10 ... FATAL=50`),
92/// and no `Unset` variant. The integer representation is stable and part of the
93/// ABI for `nros_platform_log_write`, so every value must be a level a sink can
94/// render; "no level of its own" is the verb [`Logger::unset_level`] instead.
95/// (The C surface's `rcl_log_severity_t` does carry rcutils's numbers and
96/// `UNSET`.) Lower value = more verbose.
97#[repr(u8)]
98#[derive(Copy, Clone, Debug, Eq, PartialEq, Ord, PartialOrd, Hash)]
99pub enum Severity {
100 /// Per-instruction granularity. Off unless `max-level-trace` is
101 /// the active ceiling.
102 Trace = 0,
103 /// Diagnostic information useful while developing.
104 Debug = 1,
105 /// Normal operation events worth surfacing once.
106 Info = 2,
107 /// Unexpected but recoverable conditions.
108 Warn = 3,
109 /// Errors the caller should surface; the system continues.
110 Error = 4,
111 /// Unrecoverable — the system is about to abort.
112 Fatal = 5,
113}
114
115impl Severity {
116 /// Short uppercase label suitable for log-line rendering.
117 #[must_use]
118 pub const fn as_str(self) -> &'static str {
119 match self {
120 Self::Trace => "TRACE",
121 Self::Debug => "DEBUG",
122 Self::Info => "INFO",
123 Self::Warn => "WARN",
124 Self::Error => "ERROR",
125 Self::Fatal => "FATAL",
126 }
127 }
128
129 /// Stable `u8` discriminant for cross-ABI use.
130 #[must_use]
131 pub const fn as_u8(self) -> u8 {
132 self as u8
133 }
134
135 /// This severity on **rcutils's number line** — the one every ROS 2
136 /// artefact outside this crate uses.
137 ///
138 /// [`as_u8`](Self::as_u8) is this crate's own compact discriminant (`0..=5`,
139 /// chosen so a level comparison is an integer compare). It is NOT what a
140 /// `rcl_interfaces/msg/Log` carries, nor what `<rclc/log.h>`'s
141 /// `rcl_log_severity_t` crosses the FFI as, nor what
142 /// `rcutils_logging_set_logger_level` takes. Those are all rcutils's
143 /// `DEBUG=10 / INFO=20 / WARN=30 / ERROR=40 / FATAL=50`.
144 ///
145 /// THE ONE SPELLING of that mapping (issue 1025's class: one number, two
146 /// derivations, agreeing until the day they do not). `nros-c`'s
147 /// `rcl_log_severity_t::from_facade` is built on this, and a test there
148 /// pins the result against the values `<rclc/log.h>` declares — which is
149 /// the strongest join available, since this crate cannot see that header.
150 ///
151 /// `Trace` takes **5**, a value inside rcutils's own `UNSET`..`DEBUG` gap:
152 /// rcutils has no TRACE, and borrowing `DEBUG`'s number would make the two
153 /// levels indistinguishable on the wire.
154 #[must_use]
155 pub const fn rcutils_level(self) -> u8 {
156 match self {
157 Self::Trace => 5,
158 Self::Debug => 10,
159 Self::Info => 20,
160 Self::Warn => 30,
161 Self::Error => 40,
162 Self::Fatal => 50,
163 }
164 }
165}
166
167/// Reconstruct a [`Severity`] from its `u8` discriminant.
168///
169/// Returns `None` for `> 5`.
170#[must_use]
171pub const fn severity_from_u8(value: u8) -> Option<Severity> {
172 match value {
173 0 => Some(Severity::Trace),
174 1 => Some(Severity::Debug),
175 2 => Some(Severity::Info),
176 3 => Some(Severity::Warn),
177 4 => Some(Severity::Error),
178 5 => Some(Severity::Fatal),
179 _ => None,
180 }
181}
182
183/// Compile-time ceiling check used by the `nros_*!` macros.
184///
185/// Returns `true` iff `severity` is at or above the image's
186/// `NROS_LOG_MAX_LEVEL` (issue 1037; builtin `trace`, so everything). A
187/// `const fn` over a build-script constant, so a macro call below the ceiling
188/// folds to `if false { .. }` and its formatting is dead code — the elimination
189/// the old `max-level-*` features gave, without a feature.
190///
191/// The ceiling is a BOUND, not a threshold: [`Logger::set_level`] still moves
192/// each logger's runtime level, and a level below the ceiling is simply
193/// unreachable ([`Logger::is_enabled`] answers `false` there). rcutils keeps
194/// the same pair (`RCUTILS_LOG_MIN_SEVERITY_*` + `set_logger_level`).
195#[must_use]
196pub const fn severity_enabled_at_compile_time(severity: Severity) -> bool {
197 // `config::MAX_LEVEL` is 6 for `off`, above `Fatal` (5): nothing passes.
198 // The value is a build-script constant, and at its builtin (0 = trace) the
199 // comparison is always true — that is the point, not a slip.
200 #[allow(clippy::absurd_extreme_comparisons)]
201 let enabled = (severity as u8) >= config::MAX_LEVEL;
202 enabled
203}
204
205/// One log entry, handed to each [`LogSink`].
206///
207/// `message` is already formatted — sinks must NOT re-format.
208#[derive(Debug)]
209pub struct Record<'a> {
210 /// Severity of the record.
211 pub severity: Severity,
212 /// Name of the originating [`Logger`].
213 pub logger_name: &'a str,
214 /// Formatted message text (no trailing newline).
215 pub message: &'a str,
216 /// File the macro invocation came from (`core::file!()`).
217 pub file: &'static str,
218 /// Line within `file` (`core::line!()`).
219 pub line: u32,
220 /// Monotonic timestamp in nanoseconds. `0` if unavailable.
221 pub timestamp_ns: u64,
222}
223
224/// Backend a log record is delivered to.
225///
226/// Implementations must be `Sync` so the dispatcher can hold them
227/// in `&'static [&dyn LogSink]`. ISR-safety is per-impl — see the
228/// table in `docs/roadmap/archived/phase-88-nros-log.md`.
229pub trait LogSink: Sync {
230 /// Render `record`. Called only when the record's severity passes
231 /// both the compile-time ceiling AND the [`Logger`]'s runtime
232 /// threshold.
233 fn log(&self, record: &Record<'_>);
234
235 /// Optional flush hook (default no-op).
236 fn flush(&self) {}
237}
238
239/// The stored byte meaning "this logger has NO level of its own", so its
240/// threshold is whatever [`Logger::default_level`] currently says.
241///
242/// phase-467 (ledger rows `c:log_severity_t` + `rust:Logger::set_default_level`).
243/// It cannot be `0`: that is `Severity::Trace`, the most verbose level, which
244/// is why storing rcutils's `UNSET` in a level byte used to select TRACE here
245/// where upstream restores a default. `u8::MAX` is outside the enum in the
246/// other direction, and being ABOVE `Fatal` is load-bearing in
247/// [`Logger::is_enabled`] — see the note there.
248const LEVEL_UNSET: u8 = u8::MAX;
249
250/// The threshold a logger with no level of its own resolves to.
251///
252/// ONE process-wide byte, which is the whole of our level hierarchy. rcutils
253/// resolves an unset logger by walking a DOTTED ANCESTRY (`x.y.z` → `x.y` →
254/// `x`) to `g_rcutils_logging_default_logger_level`; `nros_log` has no
255/// ancestry — [`get_logger`] is exact string equality over [`MAX_LOGGERS`]
256/// slots — so that walk degenerates here to exactly one step, and one step is
257/// what this is.
258///
259/// Deliberately not built further, and phase-467 recorded that as PERMANENT on
260/// ledger row `c:log_severity_t` rather than as work. A dotted name is accepted
261/// and is just a name with a dot in it; what is missing is the PARENT, and the
262/// two things that would give it one are both absent for the same reason.
263/// Upstream keys a level by NAME (`rcutils_logging_set_logger_level(const char
264/// *, int)` writes an allocator-backed severity map), so an ancestor there can
265/// carry a level without being a logger; here the level is an `AtomicU8` INSIDE
266/// the [`Logger`], so an ancestor would have to occupy one of the 32 slots to
267/// hold one. And the producer of dotted names upstream, `Logger::get_child`,
268/// has no allocator here to concatenate `parent.child` with. A resolver for a
269/// hierarchy nothing can construct is not a missing feature.
270///
271/// RFC-0102 reversed that and phase-479 built it: the premises went stale
272/// ([`get_or_create_logger`] copies runtime names into a static arena,
273/// `parent.child` fits a 48-byte stack buffer, and the ancestors a `get_child`
274/// produces are loggers already). The hierarchy is now a parent pointer on
275/// [`Logger`], linked at creation, and this byte is the LAST step of the walk
276/// rather than the only one.
277static DEFAULT_LEVEL: AtomicU8 = AtomicU8::new(Severity::Info as u8);
278
279/// A named logger with a runtime severity threshold.
280///
281/// A logger constructed with [`Logger::new`] has NO level of its own and
282/// follows [`Logger::default_level`] (itself [`Severity::Info`] until someone
283/// calls [`Logger::set_default_level`]). [`Logger::with_level`] and
284/// [`Logger::set_level`] give it one; [`Logger::unset_level`] takes it away
285/// again. Use [`register_logger`] to publish a `'static Logger` so multiple
286/// call sites with the same name share the same threshold.
287pub struct Logger {
288 name: &'static str,
289 /// Either a [`Severity`] discriminant or the private `LEVEL_UNSET`.
290 level: AtomicU8,
291 /// RFC-0102 D2 — the nearest EXISTING ancestor by dotted name (`a.b` for
292 /// `a.b.c`, else `a`), or null. A logger with no level of its own resolves
293 /// through this chain before falling to [`Logger::default_level`], which is
294 /// rcutils's effective-level rule. Set when a logger is published to the
295 /// intern table ([`register_logger`], [`get_or_create_logger`]), never on
296 /// the log path. Only ever points at a logger whose name is a STRICT
297 /// dotted prefix of this one's, so the chain is acyclic and shorter than
298 /// [`MAX_LOGGERS`].
299 parent: AtomicPtr<Logger>,
300 /// RFC-0102 D4 — set when a NODE's accessor resolves this logger
301 /// ([`resolve_node_logger`]). The `/rosout` sink publishes by it: upstream
302 /// rcl publishes only through a publisher correlated with a node's logger.
303 node: AtomicBool,
304}
305
306impl Logger {
307 /// `const`-construct with NO level of its own — the logger follows
308 /// [`Logger::default_level`], which is [`Severity::Info`] until something
309 /// moves it.
310 ///
311 /// phase-467: this stored `Severity::Info` outright until the process
312 /// default existed, and "the author wrote `new`" then looked exactly like
313 /// "the author wrote `with_level(.., Info)`". They are different
314 /// statements — one is a choice and the other is the absence of one — and
315 /// telling them apart is what lets [`Logger::set_default_level`] move the
316 /// first without overriding the second.
317 #[must_use]
318 pub const fn new(name: &'static str) -> Self {
319 Self {
320 name,
321 level: AtomicU8::new(LEVEL_UNSET),
322 parent: AtomicPtr::new(core::ptr::null_mut()),
323 node: AtomicBool::new(false),
324 }
325 }
326
327 /// `const`-construct with an explicit threshold.
328 #[must_use]
329 pub const fn with_level(name: &'static str, level: Severity) -> Self {
330 Self {
331 name,
332 level: AtomicU8::new(level as u8),
333 parent: AtomicPtr::new(core::ptr::null_mut()),
334 node: AtomicBool::new(false),
335 }
336 }
337
338 /// Logger name (used as `Record::logger_name`).
339 #[must_use]
340 pub const fn name(&self) -> &'static str {
341 self.name
342 }
343
344 /// The threshold this logger actually filters on — its own level if it has
345 /// one, otherwise its nearest ancestor's (RFC-0102 D2), otherwise
346 /// [`Logger::default_level`].
347 ///
348 /// This is `rcutils_logging_get_logger_effective_level`'s answer, not
349 /// `rcutils_logging_get_logger_level`'s: it is the number that decides
350 /// whether a record is emitted, which is the question a call site asks.
351 /// There is deliberately no accessor for "is a level set on this logger",
352 /// because nothing in the tree has a use for the difference and an
353 /// accessor per language is three more names for one fact.
354 #[must_use]
355 pub fn level(&self) -> Severity {
356 severity_from_u8(self.effective_level_byte()).unwrap_or(Severity::Info)
357 }
358
359 /// The nearest ancestor this logger resolves an unset level through, if
360 /// any (RFC-0102 D2). `None` for a root, and for every logger not yet
361 /// published to the intern table.
362 #[must_use]
363 pub fn parent(&self) -> Option<&'static Logger> {
364 let p = self.parent.load(Ordering::Acquire);
365 // SAFETY: `parent` is only ever stored from a `&'static Logger` (see
366 // `link_published`), and loggers are never freed.
367 if p.is_null() {
368 None
369 } else {
370 Some(unsafe { &*p })
371 }
372 }
373
374 /// Whether a node's accessor resolved this logger (RFC-0102 D4).
375 #[must_use]
376 pub fn is_node_logger(&self) -> bool {
377 self.node.load(Ordering::Relaxed)
378 }
379
380 /// Own level byte if set; else the first set level up the parent chain;
381 /// else the process default. The walk is bounded by [`MAX_LOGGERS`] even
382 /// though the chain is acyclic by construction, so a defect elsewhere can
383 /// cost a wrong answer but never a hang on the log path.
384 #[inline]
385 fn effective_level_byte(&self) -> u8 {
386 let own = self.level.load(Ordering::Relaxed);
387 if own != LEVEL_UNSET {
388 return own;
389 }
390 let mut p = self.parent.load(Ordering::Acquire);
391 let mut hops = 0;
392 while !p.is_null() && hops < MAX_LOGGERS {
393 // SAFETY: as in `parent()`.
394 let ancestor: &Logger = unsafe { &*p };
395 let level = ancestor.level.load(Ordering::Relaxed);
396 if level != LEVEL_UNSET {
397 return level;
398 }
399 p = ancestor.parent.load(Ordering::Acquire);
400 hops += 1;
401 }
402 DEFAULT_LEVEL.load(Ordering::Relaxed)
403 }
404
405 /// Give this logger a level of its own. It stops following
406 /// [`Logger::default_level`] until [`Logger::unset_level`].
407 pub fn set_level(&self, level: Severity) {
408 self.level.store(level as u8, Ordering::Relaxed);
409 }
410
411 /// Take this logger's own level away, so it follows
412 /// [`Logger::default_level`] again.
413 ///
414 /// `rcutils_logging_set_logger_level(name, RCUTILS_LOG_SEVERITY_UNSET)`'s
415 /// effect, and what `rclc_logger_set_level(logger, RCLC_LOG_SEVERITY_UNSET)`
416 /// reaches. phase-467.
417 ///
418 /// rclrs spells this `logger.set_level(LogSeverity::Unset)`. Here it is a verb,
419 /// because [`Severity`] has no `Unset`: its values are the sink ABI.
420 pub fn unset_level(&self) {
421 self.level.store(LEVEL_UNSET, Ordering::Relaxed);
422 }
423
424 /// The threshold every logger with no level of its own filters on.
425 ///
426 /// [`Severity::Info`] until [`Logger::set_default_level`] moves it, which
427 /// is `RCUTILS_DEFAULT_LOGGER_DEFAULT_LEVEL`'s value and upstream's
428 /// starting point too.
429 #[must_use]
430 pub fn default_level() -> Severity {
431 severity_from_u8(DEFAULT_LEVEL.load(Ordering::Relaxed)).unwrap_or(Severity::Info)
432 }
433
434 /// Move the threshold that every logger WITHOUT a level of its own filters
435 /// on — `rclrs::Logger::set_default_level`.
436 ///
437 /// Takes effect immediately and retroactively: a `static LOGGER:
438 /// Logger = Logger::new("x")` that was compiled into the image long before
439 /// this call follows it, because "no level of its own" is a stored state
440 /// and not a value copied in at construction. That is the whole reason
441 /// this is a capability rather than a re-export of
442 /// `DEFAULT_LOGGER.set_level`, which moves the threshold of the ONE logger
443 /// named `"nros"` (ledger row `rust:Logger::set_default_level`).
444 ///
445 /// It does NOT override a logger that states its own level: after
446 /// `with_level(.., Warn)` or `set_level(Warn)`, `Warn` wins.
447 ///
448 /// Takes [`Severity`], not rclrs's `LogSeverity`: it has a `Trace` level rclrs
449 /// lacks and no `Unset`. Where rclrs passes `Unset` to restore the default
450 /// default, pass `Severity::Info`, which is what `Unset` restores upstream.
451 pub fn set_default_level(level: Severity) {
452 DEFAULT_LEVEL.store(level as u8, Ordering::Relaxed);
453 }
454
455 /// Whether a record at `severity` would be emitted by this
456 /// logger AT RUNTIME.
457 ///
458 /// THE HOT PATH of every log macro, on every target, so the shape here is
459 /// measured rather than chosen (phase-467; the figures below are for the
460 /// two-level own-or-default form that preceded RFC-0102's ancestor walk). Resolving the unset level
461 /// SELECTS the byte to compare against and compares once, instead of
462 /// comparing twice and short-circuiting: measured at an inlined call site
463 /// with `rustc -O`, the select form is 13 instructions on
464 /// `thumbv7m-none-eabi` and **branch-free** (LLVM predicates the whole
465 /// fallback into one `ittt eq` block) against 16 with a branch for the
466 /// short-circuit form, and 10 against 12 on `x86_64`. The cost over the
467 /// single-load original (8 thumb / 4 x86_64 instructions) is one compare
468 /// against an immediate, plus a byte load of one process-global that a
469 /// logger with its own level never performs.
470 ///
471 /// `LEVEL_UNSET` being ABOVE `Fatal` rather than below `Trace` is what
472 /// keeps this correct if the select is ever reordered: `severity >=
473 /// u8::MAX` is false for every `Severity`, so an unresolved sentinel can
474 /// only ever suppress a record, never emit one at the most verbose level —
475 /// which is the failure `0` had.
476 ///
477 /// RFC-0102 D2 changed the unset arm: it now walks the parent chain before
478 /// the process default. A logger WITH its own level still costs one load
479 /// and one compare; an unset root pays one extra pointer load; each
480 /// ancestor without a level of its own costs one more. No string work, on
481 /// any arm.
482 #[must_use]
483 ///
484 /// The image's compile-time CEILING (`NROS_LOG_MAX_LEVEL`, issue 1037) is
485 /// applied here too, first: a runtime level below it is unreachable. That
486 /// is what brings the C and C++ surfaces under the same bound — their
487 /// macros format on the C side and reach the facade through this check
488 /// (`rclc_log_emit_at`, `nros_log_is_enabled`), so the ceiling the Rust
489 /// macros fold away at compile time filters theirs at the FFI boundary.
490 pub fn is_enabled(&self, severity: Severity) -> bool {
491 severity_enabled_at_compile_time(severity)
492 && (severity as u8) >= self.effective_level_byte()
493 }
494
495 /// Whether a record at `severity` would be emitted, given both this
496 /// logger's runtime threshold AND a per-call-site throttle window.
497 ///
498 /// phase-417 W4.d. The order is load-bearing and is the same order
499 /// `rclcpp` uses: the SEVERITY test runs first, so a record the level
500 /// already filters does not consume the throttle window. Reversing them
501 /// makes a raised-then-lowered log level lose its first record for a whole
502 /// interval, which is the shape of bug nobody reports because it looks
503 /// like the throttle working.
504 ///
505 /// Consumes the window when it returns `true`, so call it exactly once per
506 /// candidate record — the `nros_*_throttle!` macros do.
507 ///
508 /// `now_ns` is the caller's monotonic clock; the macros pass
509 /// [`__timestamp_ns`]. Taking it as an argument rather than reading the
510 /// clock here is what lets the whole rule be tested without a platform
511 /// port, and is the same shape `rclcpp::RCLCPP_*_THROTTLE` uses when it
512 /// asks for a `Clock`.
513 #[must_use]
514 pub fn is_enabled_throttled(
515 &self,
516 severity: Severity,
517 state: &ThrottleState,
518 now_ns: u64,
519 interval_ns: u64,
520 ) -> bool {
521 self.is_enabled(severity) && state.should_log(now_ns, interval_ns)
522 }
523
524 /// Hand `record` to every registered sink, after the runtime
525 /// threshold check.
526 ///
527 /// Macros call this; user code should not.
528 pub fn dispatch(&self, record: &Record<'_>) {
529 if !self.is_enabled(record.severity) {
530 return;
531 }
532 dispatch_to_sinks(record);
533 }
534}
535
536// -----------------------------------------------------------------------------
537// Static intern table for `get_logger("name")`. Bounded; no alloc.
538// -----------------------------------------------------------------------------
539
540/// Maximum number of named loggers that can be registered via
541/// [`register_logger`]. Beyond this, [`get_logger`] returns
542/// [`DEFAULT_LOGGER`].
543pub const MAX_LOGGERS: usize = 32;
544
545/// Catch-all logger returned when the requested name is not
546/// registered (or the intern table is full).
547pub static DEFAULT_LOGGER: Logger = Logger::new("nros");
548
549mod intern {
550 use super::{AtomicPtr, Logger, MAX_LOGGERS, Ordering};
551
552 pub(super) struct InternTable {
553 slots: [AtomicPtr<Logger>; MAX_LOGGERS],
554 }
555
556 impl InternTable {
557 /// Every published logger, in slot order.
558 pub(super) fn iter(&self) -> impl Iterator<Item = &'static Logger> + '_ {
559 self.slots.iter().map_while(|slot| {
560 let ptr = slot.load(Ordering::Acquire);
561 // SAFETY: same publication invariant as `lookup`.
562 if ptr.is_null() {
563 None
564 } else {
565 Some(unsafe { &*ptr })
566 }
567 })
568 }
569
570 pub(super) const fn new() -> Self {
571 // `AtomicPtr::new` is `const` on both `core::sync::atomic`
572 // and `portable_atomic`, so we can initialise the array
573 // by repeating the call rather than naming a `const` —
574 // which clippy flags as interior-mutable.
575 #[allow(clippy::declare_interior_mutable_const)]
576 const NULL: AtomicPtr<Logger> = AtomicPtr::new(core::ptr::null_mut());
577 Self {
578 slots: [NULL; MAX_LOGGERS],
579 }
580 }
581
582 pub(super) fn lookup(&self, name: &str) -> Option<&'static Logger> {
583 for slot in &self.slots {
584 let ptr = slot.load(Ordering::Acquire);
585 if ptr.is_null() {
586 return None;
587 }
588 // SAFETY: pointer published via Release after the
589 // owner constructed a `'static Logger`. The Acquire
590 // load synchronizes.
591 let logger: &'static Logger = unsafe { &*ptr };
592 if logger.name() == name {
593 return Some(logger);
594 }
595 }
596 None
597 }
598
599 pub(super) fn insert(&self, logger: &'static Logger) -> Option<&'static Logger> {
600 if let Some(existing) = self.lookup(logger.name()) {
601 return Some(existing);
602 }
603 let ptr = logger as *const _ as *mut Logger;
604 for slot in &self.slots {
605 if slot
606 .compare_exchange(
607 core::ptr::null_mut(),
608 ptr,
609 Ordering::AcqRel,
610 Ordering::Acquire,
611 )
612 .is_ok()
613 {
614 return Some(logger);
615 }
616 let existing_ptr = slot.load(Ordering::Acquire);
617 if !existing_ptr.is_null() {
618 // SAFETY: same publication invariant as `lookup`.
619 let existing: &'static Logger = unsafe { &*existing_ptr };
620 if existing.name() == logger.name() {
621 return Some(existing);
622 }
623 }
624 }
625 None
626 }
627 }
628}
629
630static INTERN: intern::InternTable = intern::InternTable::new();
631
632/// The dotted ancestors of `name`, nearest first: `a.b.c` yields `a.b`, `a`.
633fn dotted_ancestors(name: &str) -> impl Iterator<Item = &str> {
634 let mut rest = name;
635 core::iter::from_fn(move || {
636 let cut = rest.rfind('.')?;
637 rest = &rest[..cut];
638 Some(rest)
639 })
640}
641
642/// RFC-0102 D2 — wire a logger that was JUST published into the hierarchy.
643///
644/// 1. Its parent is its nearest EXISTING dotted ancestor.
645/// 2. Every published logger whose current parent is a FARTHER ancestor than
646/// `new` (or which has none) and whose name has `new`'s as a dotted prefix
647/// is re-pointed at `new`. So the result does not depend on creation order:
648/// `a.b.c` created before `a.b` still resolves through `a.b` once it exists.
649///
650/// Runs on publication only — one pass over at most [`MAX_LOGGERS`] slots.
651/// Creation is expected at initialisation; two loggers created at the same
652/// instant from different threads can leave a link one level FARTHER than
653/// ideal, never one pointing at a non-ancestor, because every store here is of
654/// a logger whose name is a strict dotted prefix of the target's.
655fn link_published(new: &'static Logger) {
656 let ptr = new as *const Logger as *mut Logger;
657 if let Some(parent) = dotted_ancestors(new.name()).find_map(|a| INTERN.lookup(a)) {
658 new.parent
659 .store(parent as *const Logger as *mut Logger, Ordering::Release);
660 }
661 let n = new.name();
662 for other in INTERN.iter() {
663 let on = other.name();
664 let is_descendant =
665 on.len() > n.len() && on.starts_with(n) && on.as_bytes()[n.len()] == b'.';
666 if !is_descendant {
667 continue;
668 }
669 let closer = match other.parent() {
670 None => true,
671 Some(current) => current.name().len() < n.len(),
672 };
673 if closer {
674 other.parent.store(ptr, Ordering::Release);
675 }
676 }
677}
678
679/// Publish through the intern table and, when THIS call did the inserting,
680/// link the logger into the hierarchy. The one spelling both publication
681/// paths use.
682fn publish(logger: &'static Logger) -> Option<&'static Logger> {
683 let published = INTERN.insert(logger)?;
684 if core::ptr::eq(published, logger) {
685 link_published(published);
686 }
687 Some(published)
688}
689
690/// Publish `logger` under its name so subsequent `get_logger`
691/// calls with that name return THIS reference.
692///
693/// On name collision returns the pre-existing entry (the input
694/// `logger` is NOT inserted). On a full table returns
695/// [`DEFAULT_LOGGER`].
696pub fn register_logger(logger: &'static Logger) -> &'static Logger {
697 publish(logger).unwrap_or(&DEFAULT_LOGGER)
698}
699
700/// Look up a registered logger by name. Returns [`DEFAULT_LOGGER`]
701/// if none is registered (call [`register_logger`] for a `'static
702/// Logger` to publish one).
703///
704/// Total — every call returns a usable handle the macros can
705/// dispatch through.
706#[must_use]
707pub fn get_logger(name: &str) -> &'static Logger {
708 INTERN.lookup(name).unwrap_or(&DEFAULT_LOGGER)
709}
710
711/// Look up a logger by name, CREATING one if the name is new.
712///
713/// phase-417 W4.d. This is the shape `rclcpp::get_logger` / `rcutils`' logger
714/// lookup have, and the one a wrapper needs: [`get_logger`] answers
715/// [`DEFAULT_LOGGER`] for an unregistered name, so a C or C++ caller doing
716/// `set_level(get_logger("nav"), Debug)` over the lookup-only form would have
717/// moved the threshold of the catch-all logger that EVERY other unregistered
718/// name also resolves to. Same call, same types, different effect — precisely
719/// the compile-and-differ RFC-0089 forbids.
720///
721/// Storage is the bounded static arena in [`pool`], sized by the
722/// `NROS_LOG_DYNAMIC_LOGGERS` knob (RFC-0102 D5: env > board > 16). Returns `None` — never a logger under the
723/// wrong name — when:
724///
725/// * `name` is empty or longer than [`MAX_LOGGER_NAME_LEN`],
726/// * the name arena or the logger arena is full,
727/// * the [`MAX_LOGGERS`] intern table is full.
728///
729/// Callers decide what an exhausted arena means for them; `nros-c` reports it
730/// and falls back to [`DEFAULT_LOGGER`] loudly rather than silently.
731///
732/// Loggers created this way are never destroyed — the arena has no free list,
733/// which is what makes the returned `&'static Logger` honest on `no_std`.
734#[must_use]
735pub fn get_or_create_logger(name: &str) -> Option<&'static Logger> {
736 if let Some(existing) = INTERN.lookup(name) {
737 return Some(existing);
738 }
739 let interned = pool::intern_name(name)?;
740 let placed = pool::place(Logger::new(interned))?;
741 // Not `register_logger`: that answers `DEFAULT_LOGGER` on a full table,
742 // which would hand back a logger under the wrong name — the exact aliasing
743 // this function exists to avoid. On a lost race `insert` returns the
744 // winner and our slot is spent, which `pool::dynamic_loggers_in_use`
745 // reports.
746 publish(placed)
747}
748
749/// Why [`Logger::create_child`] made no child — RFC-0102 D1.
750///
751/// rclrs's `create_child` is fallible too (`Result<Logger, RclrsError>`), so a
752/// Rust caller chooses its own fallback (`parent.create_child("x").unwrap_or(parent)`).
753/// The C and C++ surfaces, whose upstream shapes cannot report failure, fall
754/// back to the parent automatically (RFC-0102 D3).
755#[derive(Debug, Clone, Copy, PartialEq, Eq)]
756pub enum ChildError {
757 /// The child's full name is longer than [`MAX_LOGGER_NAME_LEN`] bytes.
758 NameTooLong {
759 /// Bytes the full name would have.
760 len: usize,
761 /// [`MAX_LOGGER_NAME_LEN`].
762 max: usize,
763 },
764 /// The full name would be empty: an empty `child_name` under the
765 /// catch-all, whose children are top-level names.
766 EmptyName,
767 /// The runtime-logger arena, its name bytes, or the intern table is full.
768 ArenaFull,
769}
770
771impl core::fmt::Display for ChildError {
772 fn fmt(&self, f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
773 match self {
774 Self::NameTooLong { len, max } => {
775 write!(
776 f,
777 "child logger name is {len} bytes, over the {max}-byte limit"
778 )
779 }
780 Self::EmptyName => f.write_str("child logger name is empty"),
781 Self::ArenaFull => f.write_str(
782 "no runtime logger slot left (arena, name bytes, or intern table is full)",
783 ),
784 }
785 }
786}
787
788impl Logger {
789 /// A logger that is a descendant of this one — rclrs's `create_child`,
790 /// rclcpp's `get_child` (RFC-0102 D1).
791 ///
792 /// Named `"{self}.{child_name}"`, except that the catch-all
793 /// ([`DEFAULT_LOGGER`]) has top-level children: its child is named
794 /// `child_name`, as rclrs does for its empty-named default logger.
795 ///
796 /// A child with no level of its own filters at its nearest ancestor's
797 /// (rcutils's rule, RFC-0102 D2), so `parent.set_level(Debug)` reaches it.
798 /// Idempotent: the same name returns the same logger, so a call inside a
799 /// log statement costs one intern-table lookup.
800 ///
801 /// Takes `&'static self` because the child links to its parent by
802 /// reference. `self` is published to the intern table first if it was
803 /// not, so a `static` parent nobody registered still passes its level on.
804 ///
805 /// # Errors
806 /// [`ChildError`] when the full name is over [`MAX_LOGGER_NAME_LEN`] or
807 /// empty, or no slot is left. The name is built in a stack buffer; nothing
808 /// is allocated.
809 pub fn create_child(
810 &'static self,
811 child_name: impl core::borrow::Borrow<str>,
812 ) -> Result<&'static Logger, ChildError> {
813 let child = child_name.borrow();
814 let top = core::ptr::eq(self, &DEFAULT_LOGGER);
815 let len = if top {
816 child.len()
817 } else {
818 self.name.len() + 1 + child.len()
819 };
820 if len == 0 {
821 return Err(ChildError::EmptyName);
822 }
823 if len > MAX_LOGGER_NAME_LEN {
824 return Err(ChildError::NameTooLong {
825 len,
826 max: MAX_LOGGER_NAME_LEN,
827 });
828 }
829 if !top && INTERN.lookup(self.name).is_none() {
830 // A full table leaves the child unlinked: it then filters at the
831 // process default, which is what an unregistered parent meant
832 // before RFC-0102 too.
833 let _ = publish(self);
834 }
835 let mut buf = [0u8; MAX_LOGGER_NAME_LEN];
836 let mut at = 0;
837 if !top {
838 buf[..self.name.len()].copy_from_slice(self.name.as_bytes());
839 at = self.name.len();
840 buf[at] = b'.';
841 at += 1;
842 }
843 buf[at..len].copy_from_slice(child.as_bytes());
844 // SAFETY: two `&str`s joined by an ASCII `.` are valid UTF-8, and the
845 // cut is at their end.
846 let name = unsafe { core::str::from_utf8_unchecked(&buf[..len]) };
847 get_or_create_logger(name).ok_or(ChildError::ArenaFull)
848 }
849}
850
851/// The published logger called `name`, if any — the lookup the `/rosout`
852/// sink filters by (RFC-0102 D4), which sees a record's name, not its logger.
853#[cfg(feature = "rosout")]
854pub(crate) fn find_published(name: &str) -> Option<&'static Logger> {
855 INTERN.lookup(name)
856}
857
858/// [`resolve_logger`] for a NODE's own logger, marking it as one — the one
859/// spelling the node-shaped accessors use (`Node::logger`,
860/// `rclc_node_get_logger`, the C++ node's), so the `/rosout` sink can publish
861/// what upstream publishes (RFC-0102 D4). The catch-all is never marked: a node
862/// whose name fell back to it would otherwise publish every unnamed logger.
863#[must_use]
864pub fn resolve_node_logger(name: &str) -> &'static Logger {
865 let logger = resolve_logger(name);
866 if !core::ptr::eq(logger, &DEFAULT_LOGGER) {
867 logger.node.store(true, Ordering::Relaxed);
868 }
869 logger
870}
871
872/// Resolve `name` to a logger — the TOTAL form of [`get_or_create_logger`],
873/// and the one spelling every node-shaped accessor uses.
874///
875/// phase-427 W5. Four accessors answer "which logger is this node's?" —
876/// `nros_node::executor::Node::logger`, `rclc_node_get_logger`,
877/// `nros_cpp_node_get_logger` and `rclc_log_get_logger`. All four had the same
878/// job and, before this, three of them called [`get_logger`], which is a
879/// LOOKUP: a node whose name nobody `register_logger`ed resolved to
880/// [`DEFAULT_LOGGER`]. Two nodes in one image therefore emitted every record
881/// under the same name, `"nros"` — the sentinel W5 replaced, arrived at by a
882/// different route.
883///
884/// This creates instead, and falls back to [`DEFAULT_LOGGER`] only when it
885/// cannot — an empty or over-long name, or an exhausted arena — and says so at
886/// WARN when it does, because the catch-all's threshold is SHARED and a silent
887/// alias makes `set_level` on the result move every other unnamed logger's bar
888/// with it. The report is ONE per process: a C++ `NROS_LOG_*` call site asks
889/// `node.get_logger()` on every line, so a per-call report would be a flood.
890///
891/// Lookup comes first, so an image that pre-registered a `'static Logger` under
892/// the node's name still gets that exact reference and its threshold.
893#[must_use]
894pub fn resolve_logger(name: &str) -> &'static Logger {
895 if let Some(logger) = get_or_create_logger(name) {
896 return logger;
897 }
898 // ONE report per process. This is reached from `Node::get_logger()`, which
899 // a C++ call site invokes inside every `NROS_LOG_*` macro — so a node whose
900 // name is longer than `MAX_LOGGER_NAME_LEN` (node names may be 64 bytes,
901 // logger names 48) would otherwise emit a warning per log line, and the
902 // diagnostic would be the flood. The first failure is the informative one:
903 // the arena only ever gets fuller.
904 static REPORTED: AtomicU8 = AtomicU8::new(0);
905 if REPORTED.swap(1, Ordering::Relaxed) != 0 {
906 return &DEFAULT_LOGGER;
907 }
908 let (used, total) = dynamic_logger_name_arena();
909 crate::log_warn!(
910 &DEFAULT_LOGGER,
911 "resolve_logger(\"{name}\"): no logger created — {} of {} slots and {used} of {total} \
912 name bytes are spent, or the name is over {} bytes. Returning the catch-all logger, \
913 whose threshold is SHARED: raise NROS_LOG_DYNAMIC_LOGGERS rather than calling \
914 set_level on this handle. Reported once per process.",
915 dynamic_loggers_in_use(),
916 dynamic_logger_capacity(),
917 MAX_LOGGER_NAME_LEN,
918 );
919 &DEFAULT_LOGGER
920}
921
922// -----------------------------------------------------------------------------
923// Sink list. Set once at `init`; read every dispatch.
924// -----------------------------------------------------------------------------
925
926static SINKS_PTR: AtomicPtr<&'static [&'static dyn LogSink]> =
927 AtomicPtr::new(core::ptr::null_mut());
928
929// issue 0710 — `init_default()` was here. It named a default this crate can no
930// longer name: the platform sink moved to `nros_platform_cffi::log`, where the
931// ABI it speaks is a dependency rather than a feature. Call
932// `nros_platform_cffi::log::init_default()`, or `init()` with your own sinks.
933
934/// Install the global sink list.
935///
936/// MUST be called at app startup BEFORE any record-emitting macro
937/// runs (otherwise the dispatch is a no-op — records are silently
938/// dropped). Calling `init` more than once swaps the list
939/// atomically; the previous pointer is leaked (intentional: the
940/// read path is lock-free so we can't safely free).
941///
942/// The sinks themselves must outlive the program (`'static`).
943pub fn init(sinks: &'static [&'static dyn LogSink]) {
944 // Indirect through a small `'static` cell so the read path
945 // dereferences a fat-pointer-sized slot rather than reading
946 // a wide pointer atomically.
947 #[cfg(feature = "alloc")]
948 {
949 let boxed: alloc::boxed::Box<&'static [&'static dyn LogSink]> =
950 alloc::boxed::Box::new(sinks);
951 let ptr = alloc::boxed::Box::into_raw(boxed);
952 SINKS_PTR.store(ptr, Ordering::Release);
953 }
954 #[cfg(not(feature = "alloc"))]
955 {
956 static CELL: SinkSlot = SinkSlot::new();
957 CELL.store(sinks);
958 SINKS_PTR.store(CELL.as_ptr(), Ordering::Release);
959 }
960 // AFTER publishing, so a record raised during the drain reaches `sinks`
961 // directly rather than joining a ring nobody will drain again. Overflow is
962 // reported by the same path (`report_lost`).
963 deliver_held();
964}
965
966#[cfg(not(feature = "alloc"))]
967struct SinkSlot {
968 inner: core::cell::UnsafeCell<Option<&'static [&'static dyn LogSink]>>,
969}
970
971#[cfg(not(feature = "alloc"))]
972// SAFETY: only written from `init`, which the user contracts to call
973// once at startup before any concurrent reader exists.
974unsafe impl Sync for SinkSlot {}
975
976#[cfg(not(feature = "alloc"))]
977impl SinkSlot {
978 const fn new() -> Self {
979 Self {
980 inner: core::cell::UnsafeCell::new(None),
981 }
982 }
983 fn store(&self, sinks: &'static [&'static dyn LogSink]) {
984 // SAFETY: see Sync note above.
985 unsafe {
986 *self.inner.get() = Some(sinks);
987 }
988 }
989 fn as_ptr(&self) -> *mut &'static [&'static dyn LogSink] {
990 self.inner.get().cast()
991 }
992}
993
994// -----------------------------------------------------------------------------
995// Appendable sink registry (phase-417 W4.d).
996//
997// `init` REPLACES the list, which is right for the board — it names, once, the
998// whole delivery it chose. It is the wrong verb for a consumer: C and C++ had
999// no way to install a sink at all (`rclc_log_init(void)` takes no arguments
1000// and hardcodes the platform default), and a library that wants to tee records
1001// to /rosout cannot call `init` without discarding whatever the board
1002// installed.
1003//
1004// So `add_sink` APPENDS, and dispatch walks both lists. The two are kept
1005// separate rather than merged into one growable list because they have
1006// different owners and different lifetimes-of-decision: `init` may be called
1007// again and swap the board's choice wholesale, and doing so must not silently
1008// unregister a consumer's sink.
1009// -----------------------------------------------------------------------------
1010
1011/// How many sinks [`add_sink`] can append on top of the [`init`] list.
1012///
1013/// Small on purpose: the appendable list is for consumers that TEE (a /rosout
1014/// bridge, a test collector), not for composing a delivery — a board composing
1015/// its own delivery passes the whole slice to [`init`].
1016pub const MAX_ADDED_SINKS: usize = 4;
1017
1018struct AddedSinks {
1019 slots: core::cell::UnsafeCell<[Option<&'static dyn LogSink>; MAX_ADDED_SINKS]>,
1020 /// Number of slots fully written. `Release` on publish, `Acquire` on read.
1021 len: AtomicUsize,
1022}
1023
1024// SAFETY: writes happen only under `ADD_LOCK` and only to the slot at index
1025// `len`, which no reader looks at until the `Release` store to `len` that
1026// follows the write is observed by an `Acquire` load. A slot is written once
1027// and never rewritten.
1028unsafe impl Sync for AddedSinks {}
1029
1030static ADDED: AddedSinks = AddedSinks {
1031 slots: core::cell::UnsafeCell::new([None; MAX_ADDED_SINKS]),
1032 len: AtomicUsize::new(0),
1033};
1034
1035/// Serialises `add_sink` against itself.
1036///
1037/// A spin lock, held for two stores with no call inside it, is admissible here
1038/// where the in-order-publish alternative is not: that one has a thread
1039/// waiting on ANOTHER thread's progress, which on a single-core RTOS with
1040/// priorities is a deadlock rather than a delay. Do not call `add_sink` from
1041/// an ISR.
1042static ADD_LOCK: AtomicBool = AtomicBool::new(false);
1043
1044/// Append `sink` to the sinks every record is delivered to.
1045///
1046/// Returns `false` when [`MAX_ADDED_SINKS`] are already registered — the sink
1047/// is NOT installed, and the caller is expected to say so rather than carry on
1048/// as if it were.
1049///
1050/// Records raised before any sink existed are replayed into `sink` here, the
1051/// same way [`init`] replays them, so the first sink to arrive still sees the
1052/// boot story regardless of which of the two calls installed it.
1053pub fn add_sink(sink: &'static dyn LogSink) -> bool {
1054 while ADD_LOCK
1055 .compare_exchange(false, true, Ordering::Acquire, Ordering::Acquire)
1056 .is_err()
1057 {
1058 core::hint::spin_loop();
1059 }
1060 let idx = ADDED.len.load(Ordering::Relaxed);
1061 let installed = if idx < MAX_ADDED_SINKS {
1062 // SAFETY: `ADD_LOCK` makes this the only writer, `idx` is beyond what
1063 // any reader may look at until the `Release` store below publishes it,
1064 // and the slot is never written again.
1065 unsafe {
1066 ADDED
1067 .slots
1068 .get()
1069 .cast::<Option<&'static dyn LogSink>>()
1070 .add(idx)
1071 .write(Some(sink));
1072 }
1073 ADDED.len.store(idx + 1, Ordering::Release);
1074 true
1075 } else {
1076 false
1077 };
1078 ADD_LOCK.store(false, Ordering::Release);
1079
1080 if installed {
1081 // The first delivery target in the program replays what was held
1082 // before it. AFTER publishing, for the reason `init` states.
1083 deliver_held();
1084 }
1085 installed
1086}
1087
1088/// How many sinks [`add_sink`] has installed.
1089#[must_use]
1090pub fn added_sink_count() -> usize {
1091 ADDED.len.load(Ordering::Acquire)
1092}
1093
1094/// Hand `record` to every sink installed by [`add_sink`]. Returns how many
1095/// saw it.
1096fn deliver_to_added(record: &Record<'_>) -> usize {
1097 let len = ADDED.len.load(Ordering::Acquire);
1098 let base = ADDED.slots.get().cast::<Option<&'static dyn LogSink>>();
1099 for idx in 0..len {
1100 // SAFETY: `idx < len`, and the `Acquire` load above pairs with the
1101 // `Release` store in `add_sink` that published slot `idx`. Slots below
1102 // `len` are immutable for the rest of the program.
1103 if let Some(sink) = unsafe { base.add(idx).read() } {
1104 sink.log(record);
1105 }
1106 }
1107 len
1108}
1109
1110/// Whether [`__timestamp_ns`] can answer with a real clock.
1111///
1112/// `false` means every `Record::timestamp_ns` is `0` and anything DERIVED from
1113/// the timestamp — the throttle windows above all of them — has no time base:
1114/// a throttled site then emits its FIRST record and nothing after it (a clock
1115/// that never moves is a window that never elapses — issue 1152). Exposed so a
1116/// wrapper can say so out loud instead of degrading quietly: without this, a
1117/// throttled C call site looks identical whether it is rate-limiting or
1118/// permanently shut.
1119#[must_use]
1120pub const fn timestamp_available() -> bool {
1121 cfg!(nros_log_clock)
1122}
1123
1124/// Current monotonic time for `Record::timestamp_ns` (issue #503).
1125///
1126/// With the platform clock (`cfg(nros_log_clock)`: the lane's platform
1127/// declares `[capabilities] clock = true`, or the `platform-clock` feature
1128/// pulled a port in — issue 1037, see `build.rs`) this reads
1129/// `nros_platform_clock_ns` — the universal per-platform export the
1130/// executor's timer accounting already links. Without it it returns `0`
1131/// ("unavailable") and imposes no link-time requirement.
1132///
1133/// Public because the emission macros expand it in user crates; not
1134/// part of the supported API surface.
1135#[doc(hidden)]
1136#[must_use]
1137pub fn __timestamp_ns() -> u64 {
1138 #[cfg(nros_log_clock)]
1139 {
1140 unsafe extern "C" {
1141 fn nros_platform_clock_ns() -> u64;
1142 }
1143 // SAFETY: bare query of the platform's monotonic us counter;
1144 // the symbol comes from whichever `nros-platform-<rtos>` port
1145 // linked the binary (the contract `PlatformSink ->
1146 // nros_platform_log_write` already relies on).
1147 unsafe { nros_platform_clock_ns() }
1148 }
1149 #[cfg(not(nros_log_clock))]
1150 {
1151 0
1152 }
1153}
1154
1155fn dispatch_to_sinks(record: &Record<'_>) {
1156 if !has_destination() {
1157 // Nothing installed yet — HOLD the record; `init` replays it into
1158 // whatever sinks the board chooses. See `early` for why this crate
1159 // does not reach for the platform sink itself: doing that (issue 0710)
1160 // put `nros_platform_log_write` on a path every binary executes, which
1161 // turned a pluggable delivery into a link-time requirement that no
1162 // Cargo feature can undo under workspace feature unification.
1163 //
1164 // It is also a better answer to issue 0708 than installing a default
1165 // was: the early records land in the sink the board picked, not in the
1166 // one dispatch guessed before the board had spoken.
1167 early::hold(record);
1168 return;
1169 }
1170 if !dispatch_guard_try_acquire() {
1171 // Another delivery is in progress — this thread's own sink logging
1172 // (recursion), or another thread. Hold it, then take the hand-off
1173 // (`early` module docs, issue 2000).
1174 early::hold(record);
1175 if dispatch_guard_try_acquire() {
1176 drain_and_release();
1177 }
1178 return;
1179 }
1180 deliver(record);
1181 drain_and_release();
1182}
1183
1184/// Whether a delivery would reach any sink.
1185///
1186/// phase-417 W4.d — the appendable list counts as much as `init`'s: a record
1187/// with at least one destination is NOT held.
1188fn has_destination() -> bool {
1189 !SINKS_PTR.load(Ordering::Acquire).is_null() || ADDED.len.load(Ordering::Acquire) > 0
1190}
1191
1192/// Hand `record` to every sink, appended ones first. Called with the dispatch
1193/// guard held.
1194fn deliver(record: &Record<'_>) {
1195 deliver_to_added(record);
1196 let ptr = SINKS_PTR.load(Ordering::Acquire);
1197 if !ptr.is_null() {
1198 // SAFETY: `init` published a valid `'static` slice reference.
1199 let sinks: &'static [&'static dyn LogSink] = unsafe { *ptr };
1200 for sink in sinks {
1201 sink.log(record);
1202 }
1203 }
1204}
1205
1206/// Deliver whatever is held, if a sink exists and no delivery is in progress.
1207/// One in progress delivers it itself before it lets go.
1208fn deliver_held() {
1209 // A loss is worth a delivery on its own: `NROS_LOG_EARLY_RECORDS = 0`
1210 // holds nothing, so the count may be all there is to report.
1211 if has_destination() && (early::pending() || lost_unreported()) && dispatch_guard_try_acquire()
1212 {
1213 drain_and_release();
1214 }
1215}
1216
1217/// With the guard held: deliver the held records, release, and take the guard
1218/// back while a record is still waiting — at most [`early::DRAIN_PASSES`]
1219/// times, which is what bounds a sink that logs (`early` module docs).
1220fn drain_and_release() {
1221 for pass in 0..early::DRAIN_PASSES {
1222 early::drain_with(&mut deliver);
1223 report_lost();
1224 dispatch_guard_release();
1225 // `SeqCst` on both: a raiser that saw the guard held published its
1226 // record before retrying the guard, so either it gets the guard or
1227 // this load sees the record.
1228 if pass + 1 == early::DRAIN_PASSES || !early::pending() || !dispatch_guard_try_acquire() {
1229 break;
1230 }
1231 }
1232}
1233
1234/// Records lost to a full hold queue, already reported. Written only with the
1235/// dispatch guard held.
1236static LOST_REPORTED: AtomicUsize = AtomicUsize::new(0);
1237
1238fn lost_unreported() -> bool {
1239 early::overflowed() != LOST_REPORTED.load(Ordering::Relaxed)
1240}
1241
1242/// With the guard held: say how many records were lost since the last report.
1243///
1244/// `nros-log` cannot know what those records said, but it does know how many
1245/// there were, and a silent hole is worse than a count. Delivered directly
1246/// rather than through dispatch, because a report that could itself be held —
1247/// and so lost — would undercount the loss it exists to state.
1248fn report_lost() {
1249 let lost = early::overflowed();
1250 let reported = LOST_REPORTED.swap(lost, Ordering::Relaxed);
1251 if lost == reported || !severity_enabled_at_compile_time(Severity::Warn) {
1252 return;
1253 }
1254 let mut message = buffer::FormatBuffer::new();
1255 let _ = core::fmt::Write::write_fmt(
1256 &mut message,
1257 format_args!(
1258 "{} log record(s) lost: more were waiting for a sink than \
1259 NROS_LOG_EARLY_RECORDS = {} holds (see `nros_log::early`)",
1260 lost - reported,
1261 early::early_depth()
1262 ),
1263 );
1264 deliver(&Record {
1265 severity: Severity::Warn,
1266 logger_name: "nros_log",
1267 message: message.as_str(),
1268 file: file!(),
1269 line: line!(),
1270 timestamp_ns: __timestamp_ns(),
1271 });
1272}
1273
1274/// Flush every registered sink, appended ones included.
1275pub fn flush() {
1276 // A record held for a busy dispatcher (issue 2000) is not flushed until it
1277 // has been delivered.
1278 deliver_held();
1279 let len = ADDED.len.load(Ordering::Acquire);
1280 let base = ADDED.slots.get().cast::<Option<&'static dyn LogSink>>();
1281 for idx in 0..len {
1282 // SAFETY: same publication invariant as `deliver_to_added`.
1283 if let Some(sink) = unsafe { base.add(idx).read() } {
1284 sink.flush();
1285 }
1286 }
1287 let ptr = SINKS_PTR.load(Ordering::Acquire);
1288 if ptr.is_null() {
1289 return;
1290 }
1291 // SAFETY: same invariant as `dispatch_to_sinks`.
1292 let sinks: &'static [&'static dyn LogSink] = unsafe { *ptr };
1293 for sink in sinks {
1294 sink.flush();
1295 }
1296}
1297
1298// -----------------------------------------------------------------------------
1299// Dispatch guard — one delivery at a time, process-wide.
1300//
1301// Held across every `sink.log()`. It breaks a sink that logs from recursing,
1302// and it keeps two threads out of the sinks at once, so a sink never sees
1303// interleaved calls. A record that finds it held is NOT dropped (issue 2000):
1304// it is held in `early` and delivered by the holder. Per-thread recursion
1305// detection would need a thread identity, which no `no_std` target here gives
1306// for free; deferral needs none.
1307// -----------------------------------------------------------------------------
1308
1309static DISPATCH_GUARD: AtomicBool = AtomicBool::new(false);
1310
1311fn dispatch_guard_try_acquire() -> bool {
1312 DISPATCH_GUARD
1313 .compare_exchange(false, true, Ordering::SeqCst, Ordering::SeqCst)
1314 .is_ok()
1315}
1316
1317fn dispatch_guard_release() {
1318 DISPATCH_GUARD.store(false, Ordering::SeqCst);
1319}
1320
1321// -----------------------------------------------------------------------------
1322// Tests (host-only).
1323// -----------------------------------------------------------------------------
1324
1325#[cfg(test)]
1326mod tests {
1327 use super::*;
1328
1329 #[test]
1330 fn severity_round_trips_through_u8() {
1331 for s in [
1332 Severity::Trace,
1333 Severity::Debug,
1334 Severity::Info,
1335 Severity::Warn,
1336 Severity::Error,
1337 Severity::Fatal,
1338 ] {
1339 assert_eq!(severity_from_u8(s.as_u8()), Some(s));
1340 }
1341 assert_eq!(severity_from_u8(99), None);
1342 }
1343
1344 #[test]
1345 fn logger_runtime_threshold_filters_below() {
1346 let logger = Logger::with_level("test_thresh", Severity::Warn);
1347 assert!(!logger.is_enabled(Severity::Info));
1348 assert!(logger.is_enabled(Severity::Warn));
1349 assert!(logger.is_enabled(Severity::Error));
1350 logger.set_level(Severity::Debug);
1351 assert!(logger.is_enabled(Severity::Info));
1352 }
1353
1354 /// phase-467, ledger rows `c:log_severity_t` + `rust:Logger::set_default_level`.
1355 ///
1356 /// ONE test rather than five, deliberately: the process default is
1357 /// process-wide state and `cargo test` runs this crate's tests as threads
1358 /// in one process, so a second test that moved it would race this one and
1359 /// the flake would read as a logic bug. It restores the default before it
1360 /// returns for the same reason.
1361 #[test]
1362 fn a_logger_with_no_level_of_its_own_follows_the_process_default() {
1363 assert_eq!(Logger::default_level(), Severity::Info, "starting default");
1364
1365 let unset = Logger::new("test_unset_follows_default");
1366 let stated = Logger::with_level("test_stated_keeps_its_own", Severity::Warn);
1367
1368 // Unset logger, untouched default: Info, exactly as before phase-467.
1369 assert_eq!(unset.level(), Severity::Info);
1370 assert!(!unset.is_enabled(Severity::Debug));
1371 assert!(unset.is_enabled(Severity::Info));
1372
1373 // Moving the default moves it RETROACTIVELY — the logger already
1374 // existed. This is what a re-export of `DEFAULT_LOGGER.set_level`
1375 // could not do.
1376 Logger::set_default_level(Severity::Debug);
1377 assert_eq!(Logger::default_level(), Severity::Debug);
1378 assert_eq!(unset.level(), Severity::Debug);
1379 assert!(unset.is_enabled(Severity::Debug));
1380 assert!(!unset.is_enabled(Severity::Trace));
1381
1382 // ...and does NOT override a logger that states its own level. If it
1383 // did, `with_level(.., Info)` and `new(..)` would be the same thing,
1384 // which is the distinction the sentinel exists to keep.
1385 assert_eq!(stated.level(), Severity::Warn);
1386 assert!(!stated.is_enabled(Severity::Info));
1387
1388 // Stating a level on the unset logger detaches it.
1389 unset.set_level(Severity::Error);
1390 Logger::set_default_level(Severity::Trace);
1391 assert_eq!(unset.level(), Severity::Error);
1392 assert!(!unset.is_enabled(Severity::Warn));
1393
1394 // ...and unsetting it re-attaches it, to the CURRENT default.
1395 unset.unset_level();
1396 assert_eq!(unset.level(), Severity::Trace);
1397 assert!(unset.is_enabled(Severity::Trace));
1398
1399 // The sentinel is outside `Severity`, in the direction that can only
1400 // ever SUPPRESS a record: `severity_from_u8` refuses it, and it is
1401 // above `Fatal`, not below `Trace` where rcutils's own `UNSET` sits.
1402 assert_eq!(severity_from_u8(LEVEL_UNSET), None);
1403 assert!(LEVEL_UNSET > Severity::Fatal.as_u8());
1404
1405 Logger::set_default_level(Severity::Info);
1406 }
1407
1408 #[test]
1409 fn unregistered_get_logger_returns_default() {
1410 let l = get_logger("definitely-not-registered-99");
1411 assert_eq!(l.name(), DEFAULT_LOGGER.name());
1412 }
1413
1414 #[test]
1415 fn registered_logger_round_trips_through_intern_table() {
1416 static LOGGER: Logger = Logger::new("test_intern_round_trip");
1417 let published = register_logger(&LOGGER);
1418 assert_eq!(published.name(), LOGGER.name());
1419 let looked_up = get_logger("test_intern_round_trip");
1420 assert!(core::ptr::eq(published, looked_up));
1421 }
1422
1423 #[test]
1424 fn compile_time_ceiling_matches_the_resolved_knob() {
1425 // `config::MAX_LEVEL` is `NROS_LOG_MAX_LEVEL` as `build.rs` resolved
1426 // it (builtin 0 = trace; 6 = off).
1427 let ceiling = severity_from_u8(config::MAX_LEVEL);
1428 for severity in [
1429 Severity::Trace,
1430 Severity::Debug,
1431 Severity::Info,
1432 Severity::Warn,
1433 Severity::Error,
1434 Severity::Fatal,
1435 ] {
1436 let enabled = ceiling.is_some_and(|c| severity >= c);
1437 assert_eq!(severity_enabled_at_compile_time(severity), enabled);
1438 // The ceiling bounds the runtime level: below it, no logger level
1439 // can switch a severity back on.
1440 static PROBE: Logger = Logger::with_level("ceiling_probe", Severity::Trace);
1441 assert_eq!(PROBE.is_enabled(severity), enabled);
1442 }
1443 }
1444}