nros_node/boot_report.rs
1//! A fixed RAM record the image writes about itself, for targets where no log
2//! sink reaches a human.
3//!
4//! # Why this exists
5//!
6//! phase-412 derived six pool counts and the executor arena for the
7//! mr-canhubk344 island, and then could not tell whether the derived image was
8//! correct. The only available signal was the ROS graph's node count, and one
9//! unchanged configuration produced 4, 0, 0, 4, 4 across five runs. Every other
10//! channel was already disqualified for that board:
11//!
12//! * The console is on `lpuart0`, which is not wired on the MR-CANHUBK344.
13//! `lpuart2` is the zenoh serial transport and cannot carry a second protocol.
14//! * `nros_log` therefore reaches nothing. Both arena diagnostics (issue 0900)
15//! go through it, so the two messages written specifically to explain an
16//! arena failure are invisible on the one board that needed them.
17//! * SEGGER RTT was tried and could not discriminate: a working image and a
18//! derived image both emitted only the Zephyr banner, and a deliberate
19//! positive control produced nothing at all.
20//! * Semihosting halts the core until a probe answers and FAULTS with no probe
21//! attached, so an image carrying it cannot run standalone.
22//!
23//! What all of those share is that they are STREAMS: they need the board to
24//! still be running, and they need somebody attached at the moment the
25//! interesting thing happens. The failure this campaign is trying to see is the
26//! opposite shape. An under-sized arena halts DURING entity creation, before
27//! the first spin, so issue 0900's advisory never prints -- the failure cannot
28//! report itself through any stream.
29//!
30//! So this is not a stream. It is a fixed-size record in RAM that the image
31//! keeps up to date as it boots, read out AFTERWARDS by halting the core and
32//! dumping memory. It survives the halt because it does not depend on anything
33//! still running, and a PARTIAL record is the useful case rather than a lost
34//! one: the last stage reached and the allocation that did not fit are exactly
35//! what names the knob to change.
36//!
37//! # Reading it
38//!
39//! The record is a `#[no_mangle]` static, so it has a symbol in the ELF and a
40//! debugger can find it without the address being wired in anywhere:
41//!
42//! ```text
43//! pyocd commander -t s32k344 -c "halt" -c "savemem <addr> <len> report.bin"
44//! python3 scripts/read-boot-report.py <elf> report.bin
45//! ```
46//!
47//! [`MAGIC`](crate::boot_report::MAGIC) distinguishes a written record from uninitialised RAM, and
48//! `BootReport::struct_size` lets a reader refuse a layout it does not know
49//! rather than decode it wrongly.
50//!
51//! # Cost, and why it is opt-in
52//!
53//! Enabled by setting `NROS_BOOT_REPORT=1` at build time (Zephyr:
54//! `CONFIG_NROS_BOOT_REPORT=y`), which makes `nros-node`'s build script emit
55//! `cfg(nros_boot_report)`. With the cfg absent every function here is an empty
56//! `#[inline(always)]` body and the static does not exist, so an image that
57//! does not opt in is byte-identical to one built before this module -- the
58//! same rule issue 0900's arena knob and phase-403's `rx_buffer_from_type()`
59//! both keep.
60//!
61//! Enabled, it costs `BootReport::struct_size` bytes of `.bss` -- 132, the
62//! same on every target because every field is a `u32` -- and a handful of
63//! relaxed atomic stores on paths that run once per entity at registration.
64//!
65//! The 132 is not a detail: it is the LENGTH an operator types into `savemem`,
66//! and this sentence said 60 for as long as the record had fifteen fields. A
67//! short dump decodes -- `read-boot-report.py` needs `33 * 4` bytes and a
68//! 100-byte one is refused, but a reader who trusts the prose over the tool
69//! spends the refusal looking at the wrong thing. Ask the tool instead:
70//! `read-boot-report.py --addr-only <elf>` prints the address AND the length,
71//! from the ELF's own symbol size.
72//!
73//! # Adding a field (phase-460 W5, for W7 and after)
74//!
75//! The record is meant to grow, and the order it grows in is the whole
76//! contract: `read-boot-report.py` decodes POSITIONALLY. So a new field is
77//! APPENDED -- after the last field, never inserted between two -- and the
78//! four edits are one commit:
79//!
80//! 1. the field on `BootReport`, its zero in `BootReport::new`, the same
81//! name in the same position on `Snapshot`, and its load in `snapshot`;
82//! 2. [`VERSION`](crate::boot_report::VERSION) bumped, so an older decoder REFUSES the record instead of
83//! reading the new word as one it knows;
84//! 3. `FIELDS` in `scripts/read-boot-report.py`, same name, same position, and
85//! `KNOWN_VERSION` to match;
86//! 4. the field count in `the_record_is_thirty_three_packed_u32s` below.
87//!
88//! `check-boot-report-layout` fails on 1 without 3, and the Rust test fails if
89//! the compiler laid the record out with padding. Appending is what keeps a
90//! dump taken from an older image decodable by eye: every word before the new
91//! one is still where it was, and the version says which words exist.
92
93#![allow(clippy::module_name_repetitions)]
94
95/// `"NRSR"` -- nano-ros self report. Written LAST, so a reader that finds it
96/// knows every field before it is already valid.
97pub const MAGIC: u32 = 0x4e52_5352;
98
99/// Layout version. Bump on any field change; a reader refuses what it does not
100/// know rather than decoding a record it would misread.
101///
102/// 4 since phase-460 W5 appended `heap_peak_bytes` and `heap_capacity_bytes`;
103/// 5 since phase-460 W7 appended `samples_dropped_too_small`;
104/// 6 since issue 1549 appended `rmw_local_queryable`;
105/// 7 since issue 1550 appended `domain_id`;
106/// 8 since issue 1573 appended `failed_alloc_arena`;
107/// 9 since issue 1036 appended the four `error_log_*` words;
108/// 10 since phase-479 W5 appended `log_dynamic_capacity` and
109/// `log_dynamic_in_use`;
110/// 11 since phase-474 I5 appended `heap_peak_at_first_spin`.
111pub const VERSION: u32 = 11;
112
113/// Which allocator refused the allocation `BootReport::failed_alloc_size`
114/// names.
115///
116/// Issue 1573. The executor ARENA and the PLATFORM HEAP share the one
117/// `failed_alloc_size` / `failed_alloc_shortfall` pair -- first writer wins,
118/// and the first failure stops the boot -- but the two are sized by different
119/// knobs, and a pair that cannot say which arena it describes names the wrong
120/// one. Measured on the Autoware Safety Island under QEMU: zenoh-pico's
121/// `_z_slist_new` asked the platform heap for 236 bytes, the console printed
122/// `HEAP EXHAUSTED`, and the decoded record told the reader to raise
123/// `NROS_EXECUTOR_ARENA_SIZE` for an arena that was 28% used.
124///
125/// Append only; `the_alloc_arena_codes_match_the_record` states the numbers
126/// `read-boot-report.py`'s `ALLOC_ARENA` restates.
127#[derive(Clone, Copy, PartialEq, Eq, Debug)]
128#[repr(u32)]
129pub enum AllocArena {
130 /// No allocation has failed, or the image predates the field.
131 None = 0,
132 /// The executor arena (`NROS_EXECUTOR_ARENA_SIZE`), claimed by entity
133 /// registration.
134 ExecutorArena = 1,
135 /// The platform heap `nros_platform_alloc` hands out of
136 /// (`CONFIG_NROS_ZEPHYR_HEAP_SIZE` on Zephyr).
137 PlatformHeap = 2,
138}
139
140/// Which rung of the knob ladder decided a knob the record carries.
141///
142/// Issue 1549. A knob's VALUE says what the image was built with; this says
143/// who decided it, which is the half a reader needs before changing it: a
144/// derived value is fixed by editing the declaration it came from, a stated
145/// one by editing the statement. Spelled once, here, and packed into the
146/// upper bits of each knob word that carries one (see the field docs).
147/// `zephyr/cmake/nros_cargo_build.cmake` records the rung as
148/// `NROS_KNOB_SOURCE_<knob>`; `build.rs` maps its spelling onto this.
149#[derive(Clone, Copy, PartialEq, Eq, Debug)]
150#[repr(u32)]
151pub enum KnobSource {
152 /// No resolver road reached this build (a cargo-only lane), so the record
153 /// cannot say. The value next to it is NOT evidence of anything.
154 NotRecorded = 0,
155 /// Nobody stated it and nothing derived it: the consumer's own default.
156 Default = 1,
157 /// Derived from the image's entity inventory.
158 Derived = 2,
159 /// Stated in Kconfig (a `.conf` fragment, a snippet, or its default).
160 Kconfig = 3,
161 /// Stated in the environment, which outranks everything: the build's for a
162 /// compile-time knob, `ROS_DOMAIN_ID` at run time for a hosted image's
163 /// domain.
164 Environment = 4,
165 /// Stated by a Zephyr snippet's Kconfig fragment (`-S <snippet>`), issue
166 /// 1550: a transport snippet is where an image that varies its link tends
167 /// to state its domain, and where one that forgets to is invisible.
168 Snippet = 5,
169 /// Stated on the cmake / west command line (`-DCONFIG_<symbol>=<n>`).
170 CommandLine = 6,
171}
172
173impl KnobSource {
174 /// The variant `build.rs` encoded as `code`, or [`KnobSource::NotRecorded`]
175 /// for a number this crate does not know.
176 #[must_use]
177 pub const fn from_code(code: u32) -> Self {
178 match code {
179 1 => Self::Default,
180 2 => Self::Derived,
181 3 => Self::Kconfig,
182 4 => Self::Environment,
183 5 => Self::Snippet,
184 6 => Self::CommandLine,
185 _ => Self::NotRecorded,
186 }
187 }
188}
189
190/// How far boot got. Monotonic, and the single most useful field: an arena
191/// failure halts during entity creation, so the stage that was NOT reached
192/// names the phase to look at.
193///
194/// Numbers follow EXECUTION ORDER, because `checkpoint` keeps the maximum
195/// and a stage that runs earlier but numbers higher would make the record
196/// claim less progress than was made. Inserting one therefore renumbers the
197/// rest and bumps [`VERSION`]; the decoder refuses a version it does not
198/// know rather than misreading it, which is what makes that safe.
199#[derive(Clone, Copy, PartialEq, Eq, Debug)]
200#[repr(u32)]
201pub enum Stage {
202 /// RAM as the loader left it. Never stored; a reader seeing this with a
203 /// valid magic has found a record that was reset but not re-entered.
204 Untouched = 0,
205 /// The record itself is initialised and the compile-time knobs are in it.
206 ///
207 /// Stamped at the TOP of the C++ entry point, before any argument is
208 /// validated, so "the image never entered nano-ros" is distinguishable
209 /// from "it entered and died before the executor". Version 1 stamped this
210 /// inside the executor constructor instead, which made those two cases
211 /// identical -- both read magic 0 -- and cost a disassembly walk to tell
212 /// apart on the first board run.
213 ReportReady = 1,
214 /// The boot config resolved: node name, namespace, locator and domain id
215 /// all parsed. Everything between here and [`Stage::ReportReady`] is
216 /// argument validation, and `BootReport::cpp_init_ret` says which check
217 /// rejected it.
218 BootConfigResolved = 2,
219 /// An `Executor` has bound its arena, so `BootReport::arena_capacity`
220 /// is the real slice length rather than the compiled constant.
221 ExecutorReady = 3,
222 /// Entity registration has begun: something claimed arena bytes.
223 ///
224 /// Stamped by [`note_alloc`] and [`note_alloc_failed`], which is to say by
225 /// the arena allocator itself rather than by any register seam. The arena
226 /// is claimed by entity registration and by nothing else, so an allocation
227 /// ATTEMPT is the event, and putting the stamp on the record's own writers
228 /// means every present and future `arena_alloc*` call site is covered by
229 /// construction -- there is no second place to remember.
230 ///
231 /// Issue 1036: nothing emitted this for three phases, so an image that ran
232 /// out of arena left the stage reading [`Stage::ExecutorReady`] -- the same
233 /// value as an image that opened its executor and died before registering
234 /// anything at all. The record named the allocation and could not say
235 /// WHERE, which is half of a diagnostic on a board where it is the only
236 /// channel.
237 ///
238 /// The interval between this and [`Stage::FirstSpin`] is where an
239 /// under-sized arena halts, so `stage == 4` with a non-zero
240 /// `BootReport::failed_alloc_shortfall` is the signature of the failure
241 /// this whole record exists to catch.
242 RegisteringEntities = 4,
243 /// RESERVED. Nothing emits this, and nothing can from inside the core.
244 ///
245 /// "Every entity the image declares was registered successfully" has no
246 /// observable moment here: an application may register lazily, which is the
247 /// same reason issue 0900's headroom advisory fires at the first spin
248 /// rather than at an end of registration that does not exist. A stamp at
249 /// the top of `spin_once` would be a claim the core cannot support.
250 ///
251 /// Kept rather than removed, and DOCUMENTED rather than left looking
252 /// unfinished (issue 1036): removing it renumbers [`Stage::FirstSpin`] and
253 /// bumps [`VERSION`] to retire a value no image can produce, and the next
254 /// reader would file the renumbering as the bug. An entry shape that DOES
255 /// know when its register pass ended -- a generated component `setup`
256 /// callback returning OK -- can stamp it without moving anything.
257 EntitiesReady = 5,
258 /// The first `spin_once` was entered, which is where issue 0900's
259 /// headroom advisory would have printed had a sink existed.
260 ///
261 /// Because [`Stage::EntitiesReady`] has no producer, this is also what
262 /// "registration finished" reads as: reaching 6 means the application
263 /// stopped registering and started spinning.
264 FirstSpin = 6,
265}
266
267#[cfg(nros_boot_report)]
268pub use enabled::*;
269
270#[cfg(nros_boot_report)]
271mod enabled {
272 use super::{AllocArena, MAGIC, Stage, VERSION};
273 use portable_atomic::{AtomicU32, Ordering};
274
275 /// The record. One per image, in `.bss`.
276 ///
277 /// `#[repr(C)]` with every field an `AtomicU32` -- which is
278 /// `repr(transparent)` over `u32` -- so the layout is exactly the sequence
279 /// of 32-bit words the reader script decodes, on every target this crate
280 /// builds for.
281 ///
282 /// Atomics rather than a `static mut` because the record is written from
283 /// registration paths that an application may reach from more than one
284 /// thread. `Relaxed` throughout: there is no ordering relationship to
285 /// establish with any other data, and the reader is a debugger that has
286 /// already halted the core.
287 #[repr(C)]
288 pub struct BootReport {
289 magic: AtomicU32,
290 version: AtomicU32,
291 struct_size: AtomicU32,
292 stage: AtomicU32,
293
294 // Compile-time, so that comparing these against what the build system
295 // BELIEVES it delivered turns a "derived value did not arrive" defect
296 // into a measurement. `scripts/check-knob-delivery.py` asserts the same
297 // identity one step earlier, at `build.ninja`; this is the same
298 // assertion made by the silicon.
299 arena_size: AtomicU32,
300 max_cbs: AtomicU32,
301 max_sc: AtomicU32,
302 max_nodes: AtomicU32,
303 default_rx_buf_size: AtomicU32,
304
305 // Runtime.
306 arena_capacity: AtomicU32,
307 arena_used: AtomicU32,
308 alloc_count: AtomicU32,
309 last_alloc_size: AtomicU32,
310 /// Bytes the allocation that FAILED asked for, or 0 if none has.
311 failed_alloc_size: AtomicU32,
312 /// Bytes by which that allocation overran the arena. This is the
313 /// number to add to `NROS_EXECUTOR_ARENA_SIZE`, which is why it is
314 /// stored rather than left to be recomputed from the two above.
315 ///
316 /// For a PLATFORM HEAP failure it is the request itself (see
317 /// [`note_heap_alloc_failed`]), and [`Self::failed_alloc_arena`] is
318 /// what says which of the two this pair describes.
319 failed_alloc_shortfall: AtomicU32,
320 /// `nros_cpp_init`'s return code, as the two's-complement bits of an
321 /// `i32`, or 0 (`NROS_CPP_RET_OK`) if it has not returned yet.
322 ///
323 /// The stage says HOW FAR init got; this says why it stopped. Without
324 /// it, every early return in that function -- a null argument, a
325 /// non-UTF-8 name, a bad domain id, a backend that refused to open --
326 /// is one indistinguishable "did not reach the executor".
327 cpp_init_ret: AtomicU32,
328 /// The LAST `NodeError` that crossed the C++ FFI, as a stable code.
329 ///
330 /// Stable here means assigned by `nros-cpp`'s exhaustive mapper, not
331 /// taken from the Rust discriminant -- a discriminant shifts whenever a
332 /// variant is inserted, and a dump decoded against the wrong numbering
333 /// names the wrong error, confidently.
334 err_class: AtomicU32,
335 /// For [`Self::err_class`] == Transport, which `TransportError`.
336 ///
337 /// The C++ ABI collapses eight distinct transport variants onto the
338 /// single code -100, which is what made an island subscription failure
339 /// undiagnosable: the return code said "transport" and nothing said
340 /// which. This is the field that separates them.
341 err_transport: AtomicU32,
342 /// Address of the `Backend(&'static str)` message, or 0.
343 ///
344 /// The pointer rather than the text: the message is a static string
345 /// already in the image, so copying it would cost the record a buffer
346 /// to hold something the reader can fetch. Paired with
347 /// [`Self::err_backend_len`].
348 err_backend_ptr: AtomicU32,
349 /// Length of the message at [`Self::err_backend_ptr`], or 0.
350 err_backend_len: AtomicU32,
351
352 // The platform heap -- the arena `nros_platform_alloc` hands out of,
353 // which on Zephyr is CONFIG_NROS_ZEPHYR_HEAP_SIZE. Appended by
354 // phase-460 W5; see "Adding a field" above for why the two words are
355 // at the END.
356 /// High-water mark of the platform heap, in bytes, or 0 if this image
357 /// never sampled it.
358 ///
359 /// `peak`, not `used`: `used` read at an arbitrary instant reports
360 /// whatever happened to be live at the moment of the read, which is
361 /// not what a size knob bounds. Issue 1424 -- the reporter behind this
362 /// (`nros_zephyr_heap_peak`) has existed and been compiled into every
363 /// Zephyr image since phase-412, and nothing read it off a board with
364 /// no console, so the one knob it could have sized
365 /// (`CONFIG_NROS_ZEPHYR_HEAP_SIZE`) was set by hand and annotated as a
366 /// guess.
367 ///
368 /// MONOTONIC here as well as at the source, so a later sample of a
369 /// heap that has since freed memory cannot lower the figure the knob
370 /// is sized from.
371 heap_peak_bytes: AtomicU32,
372 /// Bytes the platform heap was given, or 0 if never sampled.
373 ///
374 /// The pair is what makes the peak actionable: a peak alone says how
375 /// much was needed and says nothing about how close to the edge the
376 /// image ran. `capacity - peak` is the headroom the gate refuses on.
377 heap_capacity_bytes: AtomicU32,
378
379 /// Samples received, ACKed and then THROWN AWAY because the
380 /// subscription's buffer was smaller than the sample. Appended by
381 /// phase-460 W7; see "Adding a field" above for why it is at the END.
382 ///
383 /// Issue 1425. A drop is a QoS fact, not a fault -- nothing halts --
384 /// which is exactly why it needs a record: the image keeps running,
385 /// every outside probe reports the subscription matched and healthy
386 /// (the transport completed and ACKed the sample before the buffer was
387 /// consulted), and the application simply never sees the message. On a
388 /// board with a console the drop announces itself in a log line. On the
389 /// island's target there is no console, so before this field the only
390 /// evidence of a dropped 13.4 KiB trajectory was that nothing arrived.
391 ///
392 /// A TOTAL, not a per-entity figure, for the reason
393 /// `executor::arena`'s `DROPPED_TAKES` is one: a per-entity counter is
394 /// a field on the arena's entry structs, which are sized by knob at
395 /// build time, so it would move every image's executor footprint to buy
396 /// a diagnostic. Non-zero here means "read the log lines, or raise
397 /// `NROS_SUBSCRIPTION_BUFFER_SIZE` and see whether it goes to zero".
398 samples_dropped_too_small: AtomicU32,
399
400 /// `Z_FEATURE_LOCAL_QUERYABLE` as this image was compiled, and who
401 /// decided it: bits 0..7 the value (0 or 1), bits 8..15 the
402 /// [`super::KnobSource`]. Appended by issue 1549.
403 ///
404 /// A service client and a service server in one image meet only
405 /// through zenoh-pico's same-session query path, so this is the word
406 /// to read when a call to the image's OWN server never returns. A
407 /// zero with source `Derived` is a finding about the declaration (it
408 /// holds no client or no server); a zero with source `Default` means
409 /// the inventory could not answer.
410 rmw_local_queryable: AtomicU32,
411
412 /// The ROS domain the session was opened on, and who stated it: bits
413 /// 0..7 the id (`DOMAIN_ID_MAX` is 232), bits 8..15 the
414 /// [`super::KnobSource`]. Appended by issue 1550.
415 ///
416 /// Stamped by the boot-config resolver from the value it RESOLVED, not
417 /// from the compiled constant, so a hosted image's `ROS_DOMAIN_ID`
418 /// shows here as `Environment`. The source of a baked domain is the
419 /// Kconfig fragment the configure found stating it: a board `.conf`,
420 /// a snippet, the command line, or none (the Kconfig default, 0). A
421 /// peer on another domain never sees this image and nothing at run
422 /// time says why, so this is the word to read first when the graph is
423 /// empty.
424 domain_id: AtomicU32,
425
426 /// Which allocator refused [`Self::failed_alloc_size`], as an
427 /// [`AllocArena`] code, or 0 if none has. Appended by issue 1573.
428 ///
429 /// Written in the same first-writer branch as the pair it qualifies,
430 /// so the three words always describe ONE failure.
431 failed_alloc_arena: AtomicU32,
432
433 // Issue 1036, appended on the same rule: every ERROR-level `nros_log`
434 // record, counted where a console-less board can be asked for it.
435 //
436 // The sweep that found these: 79 `log_error!`/`log_fatal!` call sites
437 // in the core, RMW, API and board crates, and about a third of them
438 // report a condition the image then LIVES WITH -- a zenoh reply-slot
439 // table that stops answering requests, an entity that never reaches
440 // `ros2 node list`, a parameter service that drops a request, a
441 // typed sample that does not deserialize. On a board whose console is
442 // not wired each of those is indistinguishable from nothing having
443 // happened. Teaching 79 sites (and the next one) to write the record
444 // is a rule nobody can keep, so the record listens to the one channel
445 // all of them already use: `boot_report::init` appends a sink to
446 // `nros_log`, and it counts ERROR and FATAL records here.
447 /// How many ERROR/FATAL `nros_log` records this boot raised.
448 /// SATURATES rather than wrapping, like the drop tally above.
449 error_log_count: AtomicU32,
450 /// Address of the FIRST such record's source FILE (`core::file!()`,
451 /// a static string already in the image), or 0 if none or if the
452 /// address does not fit 32 bits. The reader resolves it from the ELF,
453 /// so the record names `file:line` without carrying a copy of either.
454 error_log_file_ptr: AtomicU32,
455 /// Length of the string at [`Self::error_log_file_ptr`].
456 error_log_file_len: AtomicU32,
457 /// Line of that first record. First-writer-wins, like
458 /// [`Self::failed_alloc_size`]: the first error is the one that
459 /// explains the boot, later ones are often its consequences.
460 error_log_line: AtomicU32,
461
462 // phase-479 W5 (RFC-0102 D5), appended on the same rule: the runtime
463 // logger arena, so `NROS_LOG_DYNAMIC_LOGGERS` is set from a
464 // measurement rather than a guess. `get_child` is a runtime call no
465 // declaration names, so the arena cannot be derived -- it can only be
466 // measured, and a console-less board needs the measurement HERE.
467 /// `nros_log::dynamic_logger_capacity()` as compiled: the
468 /// `NROS_LOG_DYNAMIC_LOGGERS` the image was built with. 0 means the
469 /// arena was declined (lookup only).
470 log_dynamic_capacity: AtomicU32,
471 /// `nros_log::dynamic_loggers_in_use()`: slots CLAIMED so far.
472 ///
473 /// Sampled at `init`, at every [`checkpoint`] and on every record the
474 /// image logs (the error-log sink sees each one), and MONOTONIC like
475 /// its source -- the arena has no free list. Equal to the capacity
476 /// means a creation has already fallen back, or the next one will.
477 log_dynamic_in_use: AtomicU32,
478
479 // phase-474 I5, appended on the same rule.
480 /// `heap_peak_bytes` as it stood when the record reached
481 /// [`Stage::FirstSpin`]: the peak of registration alone. The running
482 /// peak above keeps rising after it -- a host graph joining, samples
483 /// in flight -- and the headroom verdict judges THAT one; this word is
484 /// what lets a reader say how much of it came after the first spin.
485 /// On the safety island the two disagreed: a FirstSpin peak looked
486 /// fine on QEMU while the heap ran out 7-8 s later, when Autoware
487 /// joined. 0 = the record never reached FirstSpin (or predates it).
488 heap_peak_at_first_spin: AtomicU32,
489 }
490
491 impl BootReport {
492 pub(crate) const fn new() -> Self {
493 Self {
494 magic: AtomicU32::new(0),
495 version: AtomicU32::new(0),
496 struct_size: AtomicU32::new(0),
497 stage: AtomicU32::new(0),
498 arena_size: AtomicU32::new(0),
499 max_cbs: AtomicU32::new(0),
500 max_sc: AtomicU32::new(0),
501 max_nodes: AtomicU32::new(0),
502 default_rx_buf_size: AtomicU32::new(0),
503 arena_capacity: AtomicU32::new(0),
504 arena_used: AtomicU32::new(0),
505 alloc_count: AtomicU32::new(0),
506 last_alloc_size: AtomicU32::new(0),
507 failed_alloc_size: AtomicU32::new(0),
508 failed_alloc_shortfall: AtomicU32::new(0),
509 cpp_init_ret: AtomicU32::new(0),
510 err_class: AtomicU32::new(0),
511 err_transport: AtomicU32::new(0),
512 err_backend_ptr: AtomicU32::new(0),
513 err_backend_len: AtomicU32::new(0),
514 heap_peak_bytes: AtomicU32::new(0),
515 heap_capacity_bytes: AtomicU32::new(0),
516 samples_dropped_too_small: AtomicU32::new(0),
517 rmw_local_queryable: AtomicU32::new(0),
518 domain_id: AtomicU32::new(0),
519 failed_alloc_arena: AtomicU32::new(0),
520 error_log_count: AtomicU32::new(0),
521 error_log_file_ptr: AtomicU32::new(0),
522 error_log_file_len: AtomicU32::new(0),
523 error_log_line: AtomicU32::new(0),
524 log_dynamic_capacity: AtomicU32::new(0),
525 log_dynamic_in_use: AtomicU32::new(0),
526 heap_peak_at_first_spin: AtomicU32::new(0),
527 }
528 }
529
530 /// Size of the record in bytes, as the reader must expect it.
531 ///
532 /// ASKED OF THE COMPILER, not counted by hand. A hand-written word
533 /// count is a second statement of the field list that drifts the first
534 /// time a field is added, and it would drift SILENTLY -- the reader
535 /// would accept the record and decode one field short. This whole
536 /// campaign is about not hand-picking numbers the build already knows.
537 #[must_use]
538 pub const fn struct_size() -> u32 {
539 // The record is all `AtomicU32`, so this is exact on every target
540 // and there is no padding for the cast to lose.
541 core::mem::size_of::<Self>() as u32
542 }
543 }
544
545 /// A plain-value copy of the record.
546 ///
547 /// Field-for-field with [`BootReport`] and in the SAME ORDER, because
548 /// `scripts/read-boot-report.py` decodes that order out of a memory dump.
549 /// A test that reads through this therefore exercises the same layout the
550 /// script assumes, which is the only thing keeping the two in step.
551 #[derive(Clone, Copy, PartialEq, Eq, Debug)]
552 pub struct Snapshot {
553 pub magic: u32,
554 pub version: u32,
555 pub struct_size: u32,
556 pub stage: u32,
557 pub arena_size: u32,
558 pub max_cbs: u32,
559 pub max_sc: u32,
560 pub max_nodes: u32,
561 pub default_rx_buf_size: u32,
562 pub arena_capacity: u32,
563 pub arena_used: u32,
564 pub alloc_count: u32,
565 pub last_alloc_size: u32,
566 pub failed_alloc_size: u32,
567 pub failed_alloc_shortfall: u32,
568 pub cpp_init_ret: u32,
569 pub err_class: u32,
570 pub err_transport: u32,
571 pub err_backend_ptr: u32,
572 pub err_backend_len: u32,
573 pub heap_peak_bytes: u32,
574 pub heap_capacity_bytes: u32,
575 pub samples_dropped_too_small: u32,
576 pub rmw_local_queryable: u32,
577 pub domain_id: u32,
578 pub failed_alloc_arena: u32,
579 pub error_log_count: u32,
580 pub error_log_file_ptr: u32,
581 pub error_log_file_len: u32,
582 pub error_log_line: u32,
583 pub log_dynamic_capacity: u32,
584 pub log_dynamic_in_use: u32,
585 pub heap_peak_at_first_spin: u32,
586 }
587
588 /// Read the record.
589 #[must_use]
590 pub fn snapshot() -> Snapshot {
591 snapshot_of(&NROS_BOOT_REPORT)
592 }
593
594 /// [`snapshot`] of any record -- the image's, or a test's own, so a test
595 /// of a first-writer-wins field does not race every other test that
596 /// writes the one static.
597 pub(crate) fn snapshot_of(r: &BootReport) -> Snapshot {
598 let g = |f: &AtomicU32| f.load(Ordering::Relaxed);
599 Snapshot {
600 magic: g(&r.magic),
601 version: g(&r.version),
602 struct_size: g(&r.struct_size),
603 stage: g(&r.stage),
604 arena_size: g(&r.arena_size),
605 max_cbs: g(&r.max_cbs),
606 max_sc: g(&r.max_sc),
607 max_nodes: g(&r.max_nodes),
608 default_rx_buf_size: g(&r.default_rx_buf_size),
609 arena_capacity: g(&r.arena_capacity),
610 arena_used: g(&r.arena_used),
611 alloc_count: g(&r.alloc_count),
612 last_alloc_size: g(&r.last_alloc_size),
613 failed_alloc_size: g(&r.failed_alloc_size),
614 failed_alloc_shortfall: g(&r.failed_alloc_shortfall),
615 cpp_init_ret: g(&r.cpp_init_ret),
616 err_class: g(&r.err_class),
617 err_transport: g(&r.err_transport),
618 err_backend_ptr: g(&r.err_backend_ptr),
619 err_backend_len: g(&r.err_backend_len),
620 heap_peak_bytes: g(&r.heap_peak_bytes),
621 heap_capacity_bytes: g(&r.heap_capacity_bytes),
622 samples_dropped_too_small: g(&r.samples_dropped_too_small),
623 rmw_local_queryable: g(&r.rmw_local_queryable),
624 domain_id: g(&r.domain_id),
625 failed_alloc_arena: g(&r.failed_alloc_arena),
626 error_log_count: g(&r.error_log_count),
627 error_log_file_ptr: g(&r.error_log_file_ptr),
628 error_log_file_len: g(&r.error_log_file_len),
629 error_log_line: g(&r.error_log_line),
630 log_dynamic_capacity: g(&r.log_dynamic_capacity),
631 log_dynamic_in_use: g(&r.log_dynamic_in_use),
632 heap_peak_at_first_spin: g(&r.heap_peak_at_first_spin),
633 }
634 }
635
636 /// The record, findable by symbol name from a debugger.
637 ///
638 /// `#[used]` because nothing in a minimal image necessarily reads it, and a
639 /// static whose only writes are through this module's functions is exactly
640 /// what a linker is entitled to discard.
641 #[unsafe(no_mangle)]
642 #[used]
643 pub static NROS_BOOT_REPORT: BootReport = BootReport::new();
644
645 /// Stamp the header and the compile-time knobs.
646 ///
647 /// Idempotent, and safe to call from more than one place -- an image with
648 /// two executors should not have to decide which one owns the record.
649 /// MAGIC is stored LAST so a reader that finds it knows the rest is there.
650 pub fn init() {
651 let r = &NROS_BOOT_REPORT;
652 r.version.store(VERSION, Ordering::Relaxed);
653 r.struct_size
654 .store(BootReport::struct_size(), Ordering::Relaxed);
655 r.arena_size
656 .store(saturate(crate::config::ARENA_SIZE), Ordering::Relaxed);
657 r.max_cbs
658 .store(saturate(crate::config::MAX_CBS), Ordering::Relaxed);
659 r.max_sc
660 .store(saturate(crate::config::MAX_SC), Ordering::Relaxed);
661 r.max_nodes
662 .store(saturate(crate::config::MAX_NODES), Ordering::Relaxed);
663 r.default_rx_buf_size.store(
664 saturate(crate::config::DEFAULT_RX_BUF_SIZE),
665 Ordering::Relaxed,
666 );
667 r.rmw_local_queryable
668 .store(crate::config::BOOT_RMW_LOCAL_QUERYABLE, Ordering::Relaxed);
669 r.log_dynamic_capacity.store(
670 saturate(nros_log::dynamic_logger_capacity()),
671 Ordering::Relaxed,
672 );
673 note_log_loggers(r);
674 install_error_log_sink();
675 r.magic.store(MAGIC, Ordering::Relaxed);
676 checkpoint(Stage::ReportReady);
677 }
678
679 /// Issue 1036 -- the sink that puts every ERROR/FATAL `nros_log` record
680 /// into the record (see the `error_log_*` fields for why).
681 struct ErrorLogRecorder;
682
683 impl nros_log::LogSink for ErrorLogRecorder {
684 fn log(&self, record: &nros_log::Record<'_>) {
685 // phase-479 W5 -- every record, not only errors: a logger is most
686 // often created just before its first record, so this is where
687 // the arena's use is current without `nros_log` having to know
688 // the record exists.
689 note_log_loggers(&NROS_BOOT_REPORT);
690 if record.severity >= nros_log::Severity::Error {
691 record_error_log(&NROS_BOOT_REPORT, record.file, record.line);
692 }
693 }
694 }
695
696 static ERROR_LOG_RECORDER: ErrorLogRecorder = ErrorLogRecorder;
697
698 /// Append [`ErrorLogRecorder`] to `nros_log`'s sinks, ONCE however many
699 /// times `init` runs (it is idempotent and an image with two executors
700 /// calls it twice). APPENDED rather than `nros_log::init`ed, so the
701 /// board's own delivery -- the console, where there is one -- is
702 /// untouched, and records raised before this point are REPLAYED into it,
703 /// so an error before the executor opened is still counted.
704 ///
705 /// If `nros_log`'s appendable list is already full the sink is not
706 /// installed; the record then simply carries no error count, which the
707 /// reader cannot tell from "no errors" -- so it is said here rather than
708 /// discovered, and the list (4) is far from full in any image today.
709 fn install_error_log_sink() {
710 static INSTALLED: core::sync::atomic::AtomicBool =
711 core::sync::atomic::AtomicBool::new(false);
712 if !INSTALLED.swap(true, Ordering::Relaxed) {
713 let _ = nros_log::add_sink(&ERROR_LOG_RECORDER);
714 }
715 }
716
717 /// phase-479 W5 -- sample the runtime-logger arena's use into the record.
718 ///
719 /// `fetch_max`, so the word never moves backwards even if a sample from an
720 /// earlier instant lands late; the source is monotonic anyway.
721 pub(crate) fn note_log_loggers(r: &BootReport) {
722 r.log_dynamic_in_use.fetch_max(
723 saturate(nros_log::dynamic_loggers_in_use()),
724 Ordering::Relaxed,
725 );
726 }
727
728 /// Count one ERROR-level log record, keeping the FIRST one's location.
729 ///
730 /// On any record, so a test can exercise first-writer-wins without racing
731 /// every other test that logs into the image's static. The count is the
732 /// first-writer gate: whoever moves it off zero writes the location, so
733 /// the three location words always describe one record.
734 pub(crate) fn record_error_log(r: &BootReport, file: &'static str, line: u32) {
735 let prev = r
736 .error_log_count
737 .fetch_update(Ordering::Relaxed, Ordering::Relaxed, |n| {
738 Some(n.saturating_add(1))
739 })
740 .unwrap_or(u32::MAX);
741 if prev == 0 {
742 // An address past 4 GiB cannot be stored in the record's u32; 0
743 // reads as "no location", never as the wrong one.
744 let ptr = u32::try_from(file.as_ptr() as usize).unwrap_or(0);
745 r.error_log_file_ptr.store(ptr, Ordering::Relaxed);
746 r.error_log_file_len.store(
747 if ptr == 0 { 0 } else { saturate(file.len()) },
748 Ordering::Relaxed,
749 );
750 r.error_log_line.store(line, Ordering::Relaxed);
751 }
752 }
753
754 /// Record that boot reached `stage`.
755 ///
756 /// MONOTONIC: a lower stage never overwrites a higher one, so a late call
757 /// on a re-entered path cannot make the record claim less progress than was
758 /// actually made. That matters because the field's whole purpose is to be
759 /// believed about a boot that did not finish.
760 pub fn checkpoint(stage: Stage) {
761 checkpoint_in(&NROS_BOOT_REPORT, stage);
762 }
763
764 /// [`checkpoint`] on any record, so a test can own one.
765 pub(crate) fn checkpoint_in(r: &BootReport, stage: Stage) {
766 let want = stage as u32;
767 note_log_loggers(r);
768 let mut cur = r.stage.load(Ordering::Relaxed);
769 while want > cur {
770 match r
771 .stage
772 .compare_exchange_weak(cur, want, Ordering::Relaxed, Ordering::Relaxed)
773 {
774 Ok(_) => {
775 // phase-474 I5 -- the peak of registration, once: only the
776 // call that moves the stage to FirstSpin (or past it from
777 // below) writes it.
778 if want >= Stage::FirstSpin as u32 && cur < Stage::FirstSpin as u32 {
779 r.heap_peak_at_first_spin
780 .store(r.heap_peak_bytes.load(Ordering::Relaxed), Ordering::Relaxed);
781 }
782 return;
783 }
784 Err(actual) => cur = actual,
785 }
786 }
787 }
788
789 /// Record the arena slice an `Executor` actually bound.
790 ///
791 /// Not the same number as `ARENA_SIZE`, and the difference is a finding
792 /// rather than noise: the arena's placement is the caller's choice
793 /// (issue 0900), so an image can compile one size and hand the executor
794 /// another. Both are in the record so a dump can say which happened.
795 pub fn note_arena_capacity(capacity: usize) {
796 NROS_BOOT_REPORT
797 .arena_capacity
798 .store(saturate(capacity), Ordering::Relaxed);
799 }
800
801 /// Record a successful arena allocation.
802 ///
803 /// Also stamps [`Stage::RegisteringEntities`]: see that variant for why the
804 /// stamp belongs to the record's writers rather than to a register seam.
805 pub fn note_alloc(size: usize, used_after: usize) {
806 let r = &NROS_BOOT_REPORT;
807 r.alloc_count.fetch_add(1, Ordering::Relaxed);
808 r.last_alloc_size.store(saturate(size), Ordering::Relaxed);
809 r.arena_used.store(saturate(used_after), Ordering::Relaxed);
810 checkpoint(Stage::RegisteringEntities);
811 }
812
813 /// Record the arena allocation that did not fit.
814 ///
815 /// FIRST writer wins, on the same reasoning as [`checkpoint`]: the first
816 /// failure is the one that explains the boot, and any later one is a
817 /// consequence of it.
818 /// Also stamps [`Stage::RegisteringEntities`], and UNCONDITIONALLY -- outside
819 /// the first-writer branch. A second failure adds nothing to the numbers but
820 /// it is still evidence that registration was in flight, and a stage that
821 /// depended on winning a race would be exactly the sort of number this
822 /// record must never print.
823 pub fn note_alloc_failed(size: usize, shortfall: usize) {
824 checkpoint(Stage::RegisteringEntities);
825 record_alloc_failure(
826 &NROS_BOOT_REPORT,
827 size,
828 shortfall,
829 AllocArena::ExecutorArena,
830 );
831 }
832
833 /// The first-writer-wins write both failure paths share, on any record.
834 ///
835 /// ONE function so the arena code cannot be written by one path and
836 /// forgotten by the other (issue 1573 was the heap path writing the pair
837 /// the arena path writes, with nothing saying whose it was).
838 pub(crate) fn record_alloc_failure(
839 r: &BootReport,
840 size: usize,
841 shortfall: usize,
842 arena: AllocArena,
843 ) {
844 if r.failed_alloc_size
845 .compare_exchange(0, saturate(size), Ordering::Relaxed, Ordering::Relaxed)
846 .is_ok()
847 {
848 r.failed_alloc_shortfall
849 .store(saturate(shortfall), Ordering::Relaxed);
850 r.failed_alloc_arena.store(arena as u32, Ordering::Relaxed);
851 }
852 }
853
854 /// Record the PLATFORM HEAP allocation that did not fit.
855 ///
856 /// phase-460 W7 / issue 1425. `nros-platform-zephyr`'s `platform.c` calls
857 /// this through the C entry below from `nros_platform_alloc`'s exhaustion
858 /// path, BEFORE the printk and before the fatal hook, so a board halted by
859 /// an exhausted heap names the request that killed it in the same two words
860 /// an exhausted executor ARENA does.
861 ///
862 /// ONE PAIR OF FIELDS FOR TWO ARENAS. They cannot both fail in a boot that
863 /// continues -- the first one to fail stops it -- and first-writer-wins is
864 /// what makes the record name the cause rather than a consequence.
865 ///
866 /// NO STAGE STAMP, which is the whole reason this is not
867 /// [`note_alloc_failed`]. That one stamps [`Stage::RegisteringEntities`]
868 /// because the executor arena is claimed by entity registration and by
869 /// nothing else. The platform heap is claimed by anything at any time --
870 /// zenoh-pico's read task, a reply buffer, a reconnect -- so stamping would
871 /// make the record claim registration was in flight on a boot that had long
872 /// since reached its first spin. `checkpoint` is monotonic, so it would be
873 /// an unfalsifiable claim: the stage would read 4 and nothing later could
874 /// correct it.
875 pub fn note_heap_alloc_failed(size: usize) {
876 // The shortfall is the REQUEST, not `size - free`: the heap is
877 // fragmented by the time it refuses, so the bytes that would have made
878 // this request fit are not the deficit against the largest free block.
879 // A number that looks like a precise deficit and is not would be sized
880 // from.
881 record_alloc_failure(&NROS_BOOT_REPORT, size, size, AllocArena::PlatformHeap);
882 }
883
884 /// [`note_heap_alloc_failed`] across the C ABI, for a platform in C.
885 #[unsafe(no_mangle)]
886 pub extern "C" fn nros_boot_report_note_heap_alloc_failed(size: usize) {
887 note_heap_alloc_failed(size);
888 }
889
890 /// Record the domain the boot-config resolver settled on, and its rung.
891 ///
892 /// Issue 1550. LAST writer wins, like [`note_cpp_init_ret`]: an image may
893 /// resolve once per component or tier, and every resolution in one image
894 /// reads the same inputs.
895 pub fn note_domain(domain_id: u32, source: super::KnobSource) {
896 NROS_BOOT_REPORT.domain_id.store(
897 (domain_id & 0xFF) | ((source as u32) << 8),
898 Ordering::Relaxed,
899 );
900 }
901
902 /// Record `nros_cpp_init`'s return code.
903 ///
904 /// LAST writer wins, unlike [`note_alloc_failed`]: an image may call
905 /// `nros_cpp_init` more than once (per component, per tier), and the
906 /// interesting one is the call that did not get through, which is the one
907 /// that leaves the stage where it stopped.
908 pub fn note_cpp_init_ret(ret: i32) {
909 NROS_BOOT_REPORT
910 .cpp_init_ret
911 .store(ret as u32, Ordering::Relaxed);
912 }
913
914 /// Record an error that crossed the FFI.
915 ///
916 /// Takes CODES, not the error type: `nros-node` must not need to know how
917 /// `nros-cpp` numbers its variants, and the numbering has to be assigned by
918 /// an exhaustive match that a new variant breaks at compile time. The caller
919 /// owns both.
920 ///
921 /// LAST writer wins. An image that fails one entity and carries on would
922 /// otherwise keep the first stumble instead of the one that stopped it, and
923 /// the failure that stops setup is the one that explains the boot.
924 pub fn note_error(class: u32, transport: u32, backend_ptr: u32, backend_len: u32) {
925 let r = &NROS_BOOT_REPORT;
926 r.err_class.store(class, Ordering::Relaxed);
927 r.err_transport.store(transport, Ordering::Relaxed);
928 r.err_backend_ptr.store(backend_ptr, Ordering::Relaxed);
929 r.err_backend_len.store(backend_len, Ordering::Relaxed);
930 }
931
932 /// Record the platform heap's high-water mark and its capacity.
933 ///
934 /// `peak` keeps the MAXIMUM, `capacity` the last value: the peak is the
935 /// figure a knob is sized from and must not be lowered by a later sample,
936 /// while the capacity is a constant of the image that a second sample can
937 /// only restate.
938 ///
939 /// Called from the port that owns the heap, because only that port can
940 /// read it: `nros_zephyr_heap_peak()` is deliberately NOT in
941 /// `nros/platform.h` (the cross-port ABI would need a stub per port for a
942 /// figure one port can produce), so the core cannot pull the number and
943 /// the platform pushes it instead. See
944 /// [`nros_boot_report_note_heap`] for the C entry point.
945 pub fn note_heap(peak: usize, capacity: usize) {
946 note_heap_in(&NROS_BOOT_REPORT, peak, capacity);
947 }
948
949 /// [`note_heap`] on any record, so a test can own one.
950 pub(crate) fn note_heap_in(r: &BootReport, peak: usize, capacity: usize) {
951 r.heap_peak_bytes
952 .fetch_max(saturate(peak), Ordering::Relaxed);
953 r.heap_capacity_bytes
954 .store(saturate(capacity), Ordering::Relaxed);
955 }
956
957 /// [`note_heap`] across the C ABI, for a platform written in C.
958 ///
959 /// `nros-platform-zephyr`'s `platform.c` calls this from
960 /// `nros_platform_alloc` and `nros_platform_realloc` -- the only two
961 /// places the heap's peak can change -- so the record is current at every
962 /// stage transition without the stage transitions having to sample
963 /// anything, and it is written on the exhaustion path BEFORE the printk
964 /// that path emits, which is the case where the board is about to stop.
965 ///
966 /// Takes `usize`, not `u32`: the saturation rule belongs on this side
967 /// (see [`saturate`]), and a C caster would truncate instead.
968 #[unsafe(no_mangle)]
969 pub extern "C" fn nros_boot_report_note_heap(peak: usize, capacity: usize) {
970 note_heap(peak, capacity);
971 }
972
973 /// Count one sample dropped because the subscription buffer was too small.
974 ///
975 /// Returns the total AFTER this drop, so a caller can throttle its log on
976 /// the same number the record carries rather than keeping a second one.
977 ///
978 /// SATURATES at `u32::MAX` instead of wrapping. A wrapping counter can
979 /// read 0 on an image that dropped four billion samples, and 0 is the one
980 /// answer here that means "nothing is wrong" -- the same rule
981 /// [`saturate`] applies to every size in the record, applied to a tally.
982 /// `fetch_update` rather than `fetch_add` is what makes that true under
983 /// the concurrent callers `take_serialized` has.
984 pub fn note_sample_dropped_too_small() -> u32 {
985 let r = &NROS_BOOT_REPORT;
986 let prev = r
987 .samples_dropped_too_small
988 .fetch_update(Ordering::Relaxed, Ordering::Relaxed, |n| {
989 Some(n.saturating_add(1))
990 })
991 .unwrap_or(u32::MAX);
992 prev.saturating_add(1)
993 }
994
995 /// [`note_sample_dropped_too_small`] across the C ABI.
996 ///
997 /// Present for the same reason [`nros_boot_report_note_heap`] is: the
998 /// counting side may be a C translation unit, and a symbol that exists in
999 /// only one of the two builds is a link error naming nothing in
1000 /// particular.
1001 #[unsafe(no_mangle)]
1002 pub extern "C" fn nros_boot_report_note_sample_dropped_too_small() -> u32 {
1003 note_sample_dropped_too_small()
1004 }
1005
1006 /// Preload the drop tally. TEST ONLY.
1007 ///
1008 /// The record's fields are private and `mod tests` is a sibling of this
1009 /// module, not a child, so it cannot reach one. The saturation rule is
1010 /// worth a test and `u32::MAX` is not reachable by calling the writer, so
1011 /// the seam is this, compiled only under `cfg(test)`.
1012 #[cfg(test)]
1013 pub fn set_samples_dropped_too_small_for_test(v: u32) {
1014 NROS_BOOT_REPORT
1015 .samples_dropped_too_small
1016 .store(v, Ordering::Relaxed);
1017 }
1018
1019 /// Preload a record's error-log tally. TEST ONLY, for the reason
1020 /// [`set_samples_dropped_too_small_for_test`] exists: the saturation rule
1021 /// is worth a test and `u32::MAX` is not reachable by calling the writer.
1022 #[cfg(test)]
1023 pub(crate) fn set_error_log_count_for_test(r: &BootReport, v: u32) {
1024 r.error_log_count.store(v, Ordering::Relaxed);
1025 }
1026
1027 /// `usize` -> `u32`, saturating.
1028 ///
1029 /// Every field is a `u32` so the record's layout does not change between a
1030 /// 32-bit board and a 64-bit host running the same tests. Saturating rather
1031 /// than truncating because a value too large to represent should read as
1032 /// "enormous", not as its low half -- a truncated 4 GiB reads as 0, which
1033 /// is the one wrong answer that looks like a normal one.
1034 fn saturate(v: usize) -> u32 {
1035 u32::try_from(v).unwrap_or(u32::MAX)
1036 }
1037}
1038
1039#[cfg(not(nros_boot_report))]
1040pub use disabled::*;
1041
1042/// No-op stubs, so call sites need no `cfg` of their own and an image that does
1043/// not opt in is byte-identical.
1044#[cfg(not(nros_boot_report))]
1045mod disabled {
1046 use super::Stage;
1047
1048 #[inline(always)]
1049 pub fn init() {}
1050
1051 #[inline(always)]
1052 pub fn checkpoint(_stage: Stage) {}
1053
1054 #[inline(always)]
1055 pub fn note_arena_capacity(_capacity: usize) {}
1056
1057 #[inline(always)]
1058 pub fn note_alloc(_size: usize, _used_after: usize) {}
1059
1060 #[inline(always)]
1061 pub fn note_alloc_failed(_size: usize, _shortfall: usize) {}
1062
1063 #[inline(always)]
1064 pub fn note_heap_alloc_failed(_size: usize) {}
1065
1066 /// The C entry point exists in BOTH builds, for the reason below.
1067 #[unsafe(no_mangle)]
1068 pub extern "C" fn nros_boot_report_note_heap_alloc_failed(_size: usize) {}
1069
1070 #[inline(always)]
1071 pub fn note_cpp_init_ret(_ret: i32) {}
1072
1073 #[inline(always)]
1074 pub fn note_domain(_domain_id: u32, _source: super::KnobSource) {}
1075
1076 #[inline(always)]
1077 pub fn note_error(_class: u32, _transport: u32, _ptr: u32, _len: u32) {}
1078
1079 #[inline(always)]
1080 pub fn note_heap(_peak: usize, _capacity: usize) {}
1081
1082 /// Always 0 without the record, and the CALLER must not care.
1083 ///
1084 /// `nros-cpp`'s take path throttles its log on its OWN counter, never on
1085 /// this return value, precisely so that an image built without the report
1086 /// keeps the log behaviour an image built with it has. A stub that decided
1087 /// the throttle would make the diagnostic depend on the diagnostic.
1088 #[inline(always)]
1089 pub fn note_sample_dropped_too_small() -> u32 {
1090 0
1091 }
1092
1093 /// The C entry point exists in BOTH builds, unlike every other stub here.
1094 ///
1095 /// The Rust half of an image takes the record from a cfg and the C half
1096 /// takes it from `CONFIG_NROS_BOOT_REPORT`; the two are set from the same
1097 /// knob and can still be built apart (a stale `cargo` artifact, a C smoke
1098 /// test). An absent symbol makes that a LINK failure naming nothing in
1099 /// particular, so the disabled build keeps an empty body instead.
1100 #[unsafe(no_mangle)]
1101 pub extern "C" fn nros_boot_report_note_heap(_peak: usize, _capacity: usize) {}
1102
1103 /// The C entry point exists in BOTH builds, for the reason above.
1104 #[unsafe(no_mangle)]
1105 pub extern "C" fn nros_boot_report_note_sample_dropped_too_small() -> u32 {
1106 0
1107 }
1108}
1109
1110#[cfg(all(test, nros_boot_report))]
1111mod tests {
1112 use super::*;
1113
1114 /// The reader decodes thirty-two u32s positionally, so the record must
1115 /// be exactly that and nothing else -- no padding, no reordering.
1116 ///
1117 /// `size_of` on the TARGET, which is the half `check-boot-report-layout.py`
1118 /// cannot see: that gate compares two source files, and this compares the
1119 /// source against what the compiler actually laid out.
1120 #[test]
1121 fn the_record_is_thirty_three_packed_u32s() {
1122 assert_eq!(BootReport::struct_size(), 33 * 4);
1123 assert_eq!(
1124 core::mem::size_of::<BootReport>(),
1125 33 * core::mem::size_of::<u32>(),
1126 "the record grew padding; the reader decodes positionally"
1127 );
1128 assert_eq!(core::mem::align_of::<BootReport>(), 4);
1129 }
1130
1131 /// Issue 1036 -- the first ERROR names where it was raised, later ones
1132 /// only count, and the count saturates rather than wrapping to the "no
1133 /// errors" zero.
1134 #[test]
1135 fn the_first_error_log_is_kept_and_the_rest_are_counted() {
1136 let r = BootReport::new();
1137 assert_eq!(snapshot_of(&r).error_log_count, 0);
1138 record_error_log(&r, "first.rs", 11);
1139 record_error_log(&r, "second.rs", 22);
1140 let s = snapshot_of(&r);
1141 assert_eq!(s.error_log_count, 2);
1142 assert_eq!(s.error_log_line, 11, "a later error relocated the first");
1143 // A board's (and a non-PIE native_sim image's) addresses fit the
1144 // record's u32; a PIE host test binary's do not, and then BOTH words
1145 // read 0 -- "no location", never a truncated wrong one.
1146 match u32::try_from("first.rs".as_ptr() as usize) {
1147 Ok(ptr) => {
1148 assert_eq!(s.error_log_file_ptr, ptr);
1149 assert_eq!(s.error_log_file_len, "first.rs".len() as u32);
1150 }
1151 Err(_) => assert_eq!((s.error_log_file_ptr, s.error_log_file_len), (0, 0)),
1152 }
1153 set_error_log_count_for_test(&r, u32::MAX);
1154 record_error_log(&r, "third.rs", 33);
1155 assert_eq!(snapshot_of(&r).error_log_count, u32::MAX, "it wrapped");
1156 }
1157
1158 /// Issue 1036 -- the channel end to end: `init` installs the sink, an
1159 /// ERROR through the ordinary macro is counted, a WARN is not.
1160 ///
1161 /// Counted as a DELTA, because the image's static is shared with every
1162 /// other test in this binary, and any of them may log an error first.
1163 #[test]
1164 fn init_counts_error_logs_into_the_record() {
1165 init();
1166 let logger = nros_log::get_logger("boot_report_test");
1167 let before = snapshot().error_log_count;
1168 nros_log::log_warn!(logger, "a warning is advisory and is not counted");
1169 assert_eq!(snapshot().error_log_count, before);
1170 nros_log::log_error!(logger, "an error a console-less board must still see");
1171 assert_eq!(snapshot().error_log_count, before.saturating_add(1));
1172 init();
1173 nros_log::log_error!(logger, "a second init must not install a second sink");
1174 assert_eq!(snapshot().error_log_count, before.saturating_add(2));
1175 }
1176
1177 /// Issue 1549 -- `build.rs` restates these numbers (it cannot name the
1178 /// crate it builds) and `read-boot-report.py` decodes them; this is the
1179 /// statement both are held to.
1180 #[test]
1181 fn the_knob_source_codes_match_the_record() {
1182 assert_eq!(KnobSource::NotRecorded as u32, 0);
1183 assert_eq!(KnobSource::Default as u32, 1);
1184 assert_eq!(KnobSource::Derived as u32, 2);
1185 assert_eq!(KnobSource::Kconfig as u32, 3);
1186 assert_eq!(KnobSource::Environment as u32, 4);
1187 assert_eq!(KnobSource::Snippet as u32, 5);
1188 assert_eq!(KnobSource::CommandLine as u32, 6);
1189 }
1190
1191 /// Issue 1573 -- `read-boot-report.py`'s `ALLOC_ARENA` restates these.
1192 #[test]
1193 fn the_alloc_arena_codes_match_the_record() {
1194 assert_eq!(AllocArena::None as u32, 0);
1195 assert_eq!(AllocArena::ExecutorArena as u32, 1);
1196 assert_eq!(AllocArena::PlatformHeap as u32, 2);
1197 }
1198
1199 /// Issue 1573 -- a PLATFORM HEAP failure is recorded as one, so the decoder
1200 /// can name `CONFIG_NROS_ZEPHYR_HEAP_SIZE` rather than the executor arena.
1201 ///
1202 /// On a record of its own: the image's static is first-writer-wins and
1203 /// [`the_first_alloc_failure_wins`] writes it, so a read-back there would
1204 /// depend on which test ran first.
1205 #[test]
1206 fn a_heap_failure_is_recorded_as_the_heap_and_an_arena_one_as_the_arena() {
1207 let heap = BootReport::new();
1208 record_alloc_failure(&heap, 236, 236, AllocArena::PlatformHeap);
1209 record_alloc_failure(&heap, 999, 512, AllocArena::ExecutorArena);
1210 let s = snapshot_of(&heap);
1211 assert_eq!(s.failed_alloc_size, 236);
1212 assert_eq!(s.failed_alloc_shortfall, 236);
1213 assert_eq!(
1214 s.failed_alloc_arena,
1215 AllocArena::PlatformHeap as u32,
1216 "a later arena failure relabelled the first, heap, failure"
1217 );
1218
1219 let arena = BootReport::new();
1220 record_alloc_failure(&arena, 100, 8, AllocArena::ExecutorArena);
1221 assert_eq!(
1222 snapshot_of(&arena).failed_alloc_arena,
1223 AllocArena::ExecutorArena as u32
1224 );
1225 assert_eq!(snapshot_of(&BootReport::new()).failed_alloc_arena, 0);
1226 }
1227
1228 /// Issue 1550 -- the domain word packs the id in the low byte and its
1229 /// rung above it, the layout `read-boot-report.py`'s `knob_word` decodes.
1230 /// (The resolver's stamp is not asserted here: every test that resolves a
1231 /// boot config writes the same static, so a read-back would race them.)
1232 #[test]
1233 fn the_domain_word_packs_the_id_and_its_rung() {
1234 note_domain(42, KnobSource::Snippet);
1235 assert_eq!(snapshot().domain_id, 42 | (5 << 8));
1236 }
1237
1238 /// The magic is written LAST, so finding it means the rest is valid.
1239 ///
1240 /// The reader leans on this to tell "the image died before it had an
1241 /// executor" apart from "the dump is at the wrong address", and it can
1242 /// only do so if the ordering actually holds.
1243 #[test]
1244 fn init_stamps_the_header_and_the_compiled_knobs() {
1245 init();
1246 let s = snapshot();
1247 assert_eq!(s.magic, MAGIC);
1248 assert_eq!(s.version, VERSION);
1249 assert_eq!(s.struct_size, BootReport::struct_size());
1250 assert_eq!(s.arena_size, crate::config::ARENA_SIZE as u32);
1251 assert_eq!(s.max_cbs, crate::config::MAX_CBS as u32);
1252 assert_eq!(s.max_nodes, crate::config::MAX_NODES as u32);
1253 assert_eq!(
1254 s.rmw_local_queryable,
1255 crate::config::BOOT_RMW_LOCAL_QUERYABLE
1256 );
1257 assert!(s.stage >= Stage::ReportReady as u32);
1258 // phase-479 W5 -- the runtime-logger arena, as compiled and as used.
1259 assert_eq!(
1260 s.log_dynamic_capacity,
1261 nros_log::dynamic_logger_capacity() as u32
1262 );
1263 assert!(s.log_dynamic_in_use as usize <= nros_log::dynamic_logger_capacity());
1264 }
1265
1266 /// phase-479 W5 -- a logger created at run time is counted by the next
1267 /// sample, and the count never goes backwards.
1268 #[test]
1269 fn the_runtime_logger_arena_use_is_sampled() {
1270 let r = BootReport::new();
1271 note_log_loggers(&r);
1272 let before = snapshot_of(&r).log_dynamic_in_use;
1273 if nros_log::dynamic_logger_capacity() > before as usize {
1274 let _ = nros_log::get_or_create_logger("boot_report_arena_sample");
1275 note_log_loggers(&r);
1276 assert!(snapshot_of(&r).log_dynamic_in_use > before);
1277 }
1278 let now = snapshot_of(&r).log_dynamic_in_use;
1279 note_log_loggers(&r);
1280 assert!(
1281 snapshot_of(&r).log_dynamic_in_use >= now,
1282 "the count went backwards"
1283 );
1284 }
1285
1286 /// A late call on a re-entered path must not make the record claim LESS
1287 /// progress than was actually made. The field's whole purpose is to be
1288 /// believed about a boot that did not finish.
1289 #[test]
1290 fn a_checkpoint_never_goes_backwards() {
1291 init();
1292 checkpoint(Stage::FirstSpin);
1293 assert_eq!(snapshot().stage, Stage::FirstSpin as u32);
1294 checkpoint(Stage::ExecutorReady);
1295 assert_eq!(
1296 snapshot().stage,
1297 Stage::FirstSpin as u32,
1298 "an earlier stage overwrote a later one"
1299 );
1300 }
1301
1302 /// phase-474 I5 -- the heap peak at FirstSpin is frozen when the stage is
1303 /// reached; the running peak keeps rising after it, which is what the
1304 /// headroom verdict judges and what the frozen word lets a reader split.
1305 #[test]
1306 fn the_first_spin_heap_peak_is_frozen_when_the_stage_is_reached() {
1307 let r = BootReport::new();
1308 note_heap_in(&r, 40_000, 102_912);
1309 checkpoint_in(&r, Stage::ExecutorReady);
1310 assert_eq!(snapshot_of(&r).heap_peak_at_first_spin, 0, "not yet");
1311 note_heap_in(&r, 77_160, 102_912);
1312 checkpoint_in(&r, Stage::FirstSpin);
1313 // The host graph joins after the first spin.
1314 note_heap_in(&r, 79_712, 102_912);
1315 checkpoint_in(&r, Stage::FirstSpin);
1316 let s = snapshot_of(&r);
1317 assert_eq!(s.heap_peak_at_first_spin, 77_160);
1318 assert_eq!(s.heap_peak_bytes, 79_712);
1319 }
1320
1321 /// The FIRST failure is the one that explains the boot; a later one is a
1322 /// consequence of it and must not overwrite the cause.
1323 #[test]
1324 fn the_first_alloc_failure_wins() {
1325 init();
1326 note_alloc_failed(100, 8);
1327 note_alloc_failed(999, 512);
1328 let s = snapshot();
1329 assert_eq!(s.failed_alloc_size, 100);
1330 assert_eq!(s.failed_alloc_shortfall, 8);
1331 assert_eq!(s.failed_alloc_arena, AllocArena::ExecutorArena as u32);
1332 }
1333
1334 /// A value too large for the field must read as enormous, not as its low
1335 /// half. A truncated 4 GiB reads as 0, which is the one wrong answer that
1336 /// looks like a normal one.
1337 #[test]
1338 fn an_unrepresentable_size_saturates_rather_than_truncating() {
1339 init();
1340 note_arena_capacity(usize::MAX);
1341 assert_eq!(snapshot().arena_capacity, u32::MAX);
1342 }
1343
1344 /// The heap PEAK is what sizes the knob, so a later sample taken after the
1345 /// image freed memory must not lower it. Issue 1424: the figure only has
1346 /// to be believed about a boot nobody watched.
1347 ///
1348 /// Through the C entry point, which is how the only producer in the tree
1349 /// (`nros-platform-zephyr/src/platform.c`) reaches it -- a test that wrote
1350 /// through `note_heap` would leave that symbol exercised by nothing.
1351 #[test]
1352 fn the_heap_peak_keeps_the_maximum_and_the_capacity_the_last_word() {
1353 init();
1354 nros_boot_report_note_heap(4096, 94208);
1355 nros_boot_report_note_heap(18352, 94208);
1356 nros_boot_report_note_heap(1024, 94208);
1357 let s = snapshot();
1358 assert_eq!(s.heap_peak_bytes, 18352, "a later sample lowered the peak");
1359 assert_eq!(s.heap_capacity_bytes, 94208);
1360 }
1361
1362 /// Issue 1425 -- a sample dropped for being too big for its buffer is
1363 /// COUNTED, and the count is in the one record a console-less board can be
1364 /// asked for.
1365 ///
1366 /// Through the C entry point, which is the one `nros-cpp`'s take path
1367 /// reaches, and asserting the RETURNED total as well as the record: the
1368 /// caller throttles its log on that return, so a writer that stored
1369 /// correctly and returned garbage would log on the wrong samples while
1370 /// this test read the field and passed.
1371 #[test]
1372 fn a_sample_dropped_for_being_too_small_is_counted_in_the_record() {
1373 init();
1374 let before = snapshot().samples_dropped_too_small;
1375 assert_eq!(
1376 nros_boot_report_note_sample_dropped_too_small(),
1377 before + 1,
1378 "the writer must return the total AFTER its own drop"
1379 );
1380 assert_eq!(snapshot().samples_dropped_too_small, before + 1);
1381 assert_eq!(nros_boot_report_note_sample_dropped_too_small(), before + 2);
1382 assert_eq!(
1383 snapshot().samples_dropped_too_small,
1384 before + 2,
1385 "the second drop did not reach the record"
1386 );
1387 }
1388
1389 /// A tally that WRAPS reads 0 on an image that dropped four billion
1390 /// samples, and 0 is the one answer here that means nothing is wrong.
1391 ///
1392 /// The same rule as [`an_unrepresentable_size_saturates_rather_than_truncating`],
1393 /// applied to a counter rather than a size. Written through the record
1394 /// directly because reaching `u32::MAX` by calling the writer is not a test
1395 /// anyone can run.
1396 #[test]
1397 fn the_drop_tally_saturates_rather_than_wrapping_to_zero() {
1398 init();
1399 set_samples_dropped_too_small_for_test(u32::MAX);
1400 assert_eq!(note_sample_dropped_too_small(), u32::MAX);
1401 assert_eq!(
1402 snapshot().samples_dropped_too_small,
1403 u32::MAX,
1404 "the tally wrapped; a dropping image would read as a healthy one"
1405 );
1406 // Leave the record where the other tests in this binary expect it.
1407 set_samples_dropped_too_small_for_test(0);
1408 }
1409}