From 84807dde4ec3740c8a9d8ae07dee68a1066e6166 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Onur=20=C3=96zkan?= Date: Sat, 7 Nov 2026 18:12:11 +0300 Subject: [PATCH] fix(diagnostics): bound formatting and release ingress before callbacks Bound UTF-8 formatting and release diagnostic ingress before invoking callbacks. Check error-ID collisions at Rust/C++ release final link. Validation: diagnostic tests, strict Clippy, Miri and final-link cases. --- docs/src/errors.md | 19 +- docs/src/logs.md | 28 ++- firmware/Makefile | 9 +- .../kaptan-err-reportable-macros/src/lib.rs | 10 +- .../tests/final_link.md | 28 +++ .../tests/final_link.py | 229 ++++++++++++++++++ .../libs/kaptan-err-reportable/src/ingress.rs | 48 ++++ .../libs/kaptan-err-reportable/src/lib.rs | 3 - firmware/libs/kaptan-log/src/facade.rs | 137 +++++++++-- firmware/libs/kaptan-log/src/lib.rs | 13 +- firmware/libs/kaptan-log/src/text.rs | 70 +++++- flake.nix | 1 + 12 files changed, 547 insertions(+), 48 deletions(-) create mode 100644 firmware/libs/kaptan-err-reportable-macros/tests/final_link.md create mode 100644 firmware/libs/kaptan-err-reportable-macros/tests/final_link.py diff --git a/docs/src/errors.md b/docs/src/errors.md index 0519906..206d4e4 100644 --- a/docs/src/errors.md +++ b/docs/src/errors.md @@ -23,8 +23,15 @@ requires a nonzero explicit ID on every variant and retains no type, variant, or module string. `Display` renders the decimal ID. Renaming, moving, or reordering a Rust variant therefore does not change its receiver contract. Missing and same-enum duplicate IDs are rejected by the derive. Reusing an ID -across error enums generates the same reserved linker symbol and fails the -final firmware build. +across error enums generates the same reserved symbol. Collision detection +requires both defining objects to participate in compilation or final linking. +It does not inspect unextracted archive members or prove catalog-wide uniqueness. +Stable ID allocation still requires review. + +The [final-link fixture](../../firmware/libs/kaptan-err-reportable-macros/tests/final_link.md) +checks Rust 1.90.0 release fat-LTO and native Linux static-library links. +Run it with `make -C firmware native-test`. Each run retains its results and +Rust compiler identity in `results.txt`. `#[kaptan_err_reportable::propagate]` turns an annotated function into a reporting point. If a reportable `Err` leaves that function, the attribute makes @@ -76,16 +83,14 @@ different reportable error is already pending. `ERROR`, subject to bounded transport admission. The payload is `{ error_id, raised_at[96] }`. `raised_at` is a zero-padded UTF-8 `file:line` prefix for the reporting point. - The message kind itself identifies an error; no level is duplicated in the - payload. Dynamic human-readable context belongs in `LOG`, while + Dynamic human-readable context belongs in `LOG`, while structured protocol failures remain in their owning response message. - Control, navigation, and safety error types are derive-ready but their live owners are not yet attached to a MAVLink worker. -F722 still uses `panic-halt`; it does not claim a live panic frame or -retained-record replay. +F722 uses `panic-halt`, without live panic reporting or retained-record replay. No diagnostic message may synchronously transmit from a panic handler, hard fault, ISR, DMA callback, or motor-inhibit path. A later target integration must inhibit outputs first, persist a validated crash record, then report it -only after the next boot’s static board telemetry is available. +only after MAVLink is available on the next boot. diff --git a/docs/src/logs.md b/docs/src/logs.md index 2d86f8a..27cef95 100644 --- a/docs/src/logs.md +++ b/docs/src/logs.md @@ -1,6 +1,6 @@ # Logs -Kaptan code uses the familiar logging macros on both host and flight targets: +Logging macros work on host and flight targets: ```rust,ignore kaptan_log::debug!("estimator waiting for IMU"); @@ -11,16 +11,22 @@ kaptan_log::trace!("prediction step complete"); ``` All five macros emit `LOG`; their level never selects a different wire -message. When a reportable firmware error escapes a reviewed +message. When a reportable firmware error escapes a `#[kaptan_err_reportable::propagate]` function, it makes one bounded admission attempt to the separate `ERROR` ingress. -`kaptan-log` formats each event once into a fixed bounded buffer and never -sends MAVLink, allocates, blocks, changes flight state, or touches DMA. The -composition fans the event into each enabled sink; the sole MAVLink worker -drains its bounded sink queue. Ordinary log text uses one 160-byte bounded -record. Reportable-error records contain the explicit ID and a static reference -to the reporting point until the MAVLink adapter copies its +`kaptan-log` formats each event once into fixed 160-byte UTF-8 storage. Its core +storage and admission paths use no allocation or blocking, and do not send +MAVLink, change flight state or touch DMA. Formatting invokes caller-supplied +`Display` implementations, which may allocate, block, ignore `fmt::Error` or do +unbounded work. Overflow stops formatters that propagate the error and latches +truncation even if a formatter ignores it. Bounded storage is not a universal +worst-case execution-time guarantee. Producers must choose formatters suitable +for their execution context. + +The composition fans the event into each enabled sink. The MAVLink worker drains +its bounded sink queue. Reportable-error records contain the explicit ID and a +static reference to the reporting point until the MAVLink adapter copies its `file:line` into the 96-byte `raised_at` field. Logs and reportable errors use independent fixed atomic ingresses; interrupt and worker producers make one nonblocking admission @@ -47,8 +53,6 @@ or the complete field when no zero is present. (2), Info (3), Warn (4), or Error (5). Off (0) is a filter-only sentinel and is never emitted as a `LOG` event. `LOG.flags` currently owns only the Truncated bit (1). -The `ERROR` message kind already means a reportable firmware error, so it has -no redundant level or flags field. `error_id` is the stable nonzero catalog number explicitly assigned to the Rust error variant. Renaming or reordering a variant does not change it. @@ -73,8 +77,8 @@ runtime log levels. F722 uses the validated filter recovered at boot, falling back to its board factory when the journal is empty or invalid. Events retain the compact typed `Level` and sink configuration retains the -compact typed `LevelFilter`. Generic schema discovery exposes the filter's -named choices to the configurator, so the UI carries no hardcoded field list. +compact typed `LevelFilter`. Schema metadata supplies the filter choices to the +configurator. Only the MAVLink adapter converts the five event levels to the typed Kaptan wire enum. diff --git a/firmware/Makefile b/firmware/Makefile index 286d14a..42ec754 100644 --- a/firmware/Makefile +++ b/firmware/Makefile @@ -1,5 +1,6 @@ override SHELL := /bin/sh override MAKEFLAGS += --no-print-directory +export CARGO_BUILD_JOBS ?= 2 .DEFAULT_GOAL := help .DELETE_ON_ERROR: @@ -29,7 +30,7 @@ ifeq ($(PRIMARY_GOAL),run) else -.PHONY: help run fmt clippy test docs pre-commit check clean +.PHONY: help run fmt clippy test native-test docs pre-commit check clean help: @printf '%s\n' 'Usage: make firmware -- ' '' \ @@ -38,6 +39,7 @@ help: ' fmt Check Rust formatting' \ ' clippy Run host and embedded Clippy checks' \ ' test Run Rust and firmware script tests' \ + ' native-test Check cross-crate error IDs at Rust/C++ release final link' \ ' docs Build Rust API documentation with warnings denied' \ ' pre-commit Run fmt, clippy, test, and docs' \ ' check Alias for pre-commit' \ @@ -58,6 +60,11 @@ test: $(CARGO) test --workspace $(CARGO_FLAGS) $(PYTHON) -m unittest \ scripts/test-analyze-fw.py scripts/test-summarize-test-coverage.py + +@$(MAKE) native-test + +native-test: + python3 libs/kaptan-err-reportable-macros/tests/final_link.py \ + --work-dir "$(or $(CARGO_TARGET_DIR),target)/native-tests/final-link" docs: RUSTDOCFLAGS='-D warnings' $(CARGO) doc --workspace --no-deps \ diff --git a/firmware/libs/kaptan-err-reportable-macros/src/lib.rs b/firmware/libs/kaptan-err-reportable-macros/src/lib.rs index 02dd7e1..d990202 100644 --- a/firmware/libs/kaptan-err-reportable-macros/src/lib.rs +++ b/firmware/libs/kaptan-err-reportable-macros/src/lib.rs @@ -1,4 +1,4 @@ -//! Attribute expansion for `kaptan-err-reportable`. +//! Error derive and reporting-attribute expansion for `kaptan-err-reportable`. use proc_macro::TokenStream; use quote::{format_ident, quote}; @@ -12,8 +12,12 @@ use syn::{ /// [`core::error::Error`] for an explicitly numbered error enum. /// /// Every variant must declare a stable nonzero -/// `#[kaptan_error(id = ...)]`. Duplicate IDs fail compilation within an enum -/// or crate and fail final linking when they originate in different crates. +/// `#[kaptan_error(id = ...)]`. The derive rejects duplicates within an enum. +/// Across enums, duplicate IDs emit the same reserved symbol. Collision detection +/// requires both defining objects to participate in compilation or final linking. +/// Unextracted archive members are not checked, so catalog allocation still needs +/// review. The fixture guide in `tests/final_link.md` describes Rust release-LTO +/// and native Linux checks. Embedded linker combinations need their own checks. #[proc_macro_derive(KaptanError, attributes(kaptan_error))] pub fn derive_kaptan_error(input: TokenStream) -> TokenStream { let input = parse_macro_input!(input as DeriveInput); diff --git a/firmware/libs/kaptan-err-reportable-macros/tests/final_link.md b/firmware/libs/kaptan-err-reportable-macros/tests/final_link.md new file mode 100644 index 0000000..43247ed --- /dev/null +++ b/firmware/libs/kaptan-err-reportable-macros/tests/final_link.md @@ -0,0 +1,28 @@ +# Cross-crate error-ID final-link checks + +From the repository root, run `nix develop -c make -C firmware native-test`. +For a separate artifact directory: + +```sh +nix develop -c env CARGO_BUILD_JOBS=2 python3 firmware/libs/kaptan-err-reportable-macros/tests/final_link.py \ + --work-dir /tmp/kaptan-final-link +``` + +The fixture builds two crates using the production `KaptanError` derive as +rlibs and staticlibs. Rust and C++ executables cover unique and duplicate IDs, +used and unused error values, and an unused second crate. Successful executables +must run. Expected duplicate failures must name `__kaptan_error_id_65401`. + +The helper seeds its fixture lock from `firmware/Cargo.lock`, verifies registry +versions, sources and checksums, then builds with Rust 1.90.0 and `--locked +--offline`. It retains source, manifests, locks, binaries, linker output and +`results.txt` with the Rust compiler identity and all twelve outcomes. Native linker flags +are Linux-specific. + +The exported `#[used]` marker detects collisions when both defining objects +participate in the link. It cannot force extraction of an unreferenced staticlib +member. The native case that calls only the first crate can therefore link despite +the duplicate ID. Rust's release-LTO fixture explicitly names the second crate +and rejects that collision. These cases do not establish catalog-wide uniqueness +across every supplied archive or every embedded linker/LTO combination. Stable +error-ID allocation still requires review. diff --git a/firmware/libs/kaptan-err-reportable-macros/tests/final_link.py b/firmware/libs/kaptan-err-reportable-macros/tests/final_link.py new file mode 100644 index 0000000..f83996f --- /dev/null +++ b/firmware/libs/kaptan-err-reportable-macros/tests/final_link.py @@ -0,0 +1,229 @@ +#!/usr/bin/env python3 +"""Exercise the actual derive across crates at the host release-LTO final link. + +Run with Python 3.11+. Build output is retained under the supplied directory. +This is a link experiment, not a trybuild or cargo-check substitute. +""" + +import argparse +import hashlib +import json +from pathlib import Path +import subprocess +import tomllib + + +def run(arguments, cwd): + return subprocess.run(arguments, cwd=cwd, text=True, capture_output=True) + + +def require_success(result): + if result.returncode: + raise RuntimeError(result.stdout + result.stderr) + + +def registry_packages(lock): + return { + (package["source"], package["name"], package["version"], package["checksum"]) + for package in tomllib.loads(lock.decode())["package"] + if package.get("source", "").startswith("registry+") + } + + +def verify_registry_packages(firmware_lock, fixture_lock): + packages = registry_packages(fixture_lock) + drift = packages - registry_packages(firmware_lock) + if drift: + raise RuntimeError( + f"fixture registry dependencies differ from firmware lock: {sorted(drift)!r}" + ) + return sorted(packages) + + +def main(): + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument("--work-dir", type=Path, required=True) + args = parser.parse_args() + work = args.work_dir.resolve() + work.mkdir(parents=True, exist_ok=True) + runtime = Path(__file__).resolve().parents[2] / "kaptan-err-reportable" + version = run(["rustc", "+1.90.0", "-vV"], work) + require_success(version) + host = next( + line.removeprefix("host: ") + for line in version.stdout.splitlines() + if line.startswith("host: ") + ) + print(version.stdout, end="") + for name in ["a", "b", "app"]: + (work / name / "src").mkdir(parents=True, exist_ok=True) + (work / "Cargo.toml").write_text(""" +[workspace] +members = ["a", "b", "app"] +resolver = "2" +[profile.release] +opt-level = 3 +codegen-units = 1 +lto = "fat" +panic = "abort" +strip = "symbols" +""") + for name in ["a", "b"]: + (work / name / "Cargo.toml").write_text(f""" +[package] +name = "error-id-{name}" +version = "0.0.0" +edition = "2024" +[lib] +crate-type = ["rlib", "staticlib"] +[features] +duplicate = [] +unused = [] +[dependencies] +kaptan-err-reportable = {{ path = {json.dumps(str(runtime))} }} +""") + unique = 65401 if name == "a" else 65402 + (work / name / "src/lib.rs").write_text(f""" +#[derive(Debug, kaptan_err_reportable::KaptanError)] +pub enum Error {{ + #[cfg_attr(feature = "duplicate", kaptan_error(id = 65401))] + #[cfg_attr(not(feature = "duplicate"), kaptan_error(id = {unique}))] + Fault, +}} + +#[unsafe(no_mangle)] +pub extern "C" fn fixture_{name}() -> u16 {{ + #[cfg(not(feature = "unused"))] + {{ kaptan_err_reportable::ReportableError::error_id(&Error::Fault).get() }} + #[cfg(feature = "unused")] + {{ {unique} }} +}} +""") + (work / "app/Cargo.toml").write_text(""" +[package] +name = "error-id-app" +version = "0.0.0" +edition = "2024" +[dependencies] +error-id-a = { path = "../a" } +error-id-b = { path = "../b" } +""") + (work / "app/src/main.rs").write_text("fn main() {}\n") + firmware_lock = (runtime.parents[1] / "Cargo.lock").read_bytes() + (work / "firmware.Cargo.lock").write_bytes(firmware_lock) + fixture_lock_path = work / "Cargo.lock" + fixture_lock_path.write_bytes(firmware_lock) + # Resolve the fixture's local workspace entries while retaining locked + # registry versions. generate-lockfile would instead select newer versions. + require_success( + run( + [ + "cargo", + "+1.90.0", + "metadata", + "--offline", + "--all-features", + "--format-version", + "1", + ], + work, + ) + ) + fixture_lock = fixture_lock_path.read_bytes() + packages = verify_registry_packages(firmware_lock, fixture_lock) + provenance = [ + f"firmware Cargo.lock SHA-256: {hashlib.sha256(firmware_lock).hexdigest()}", + f"fixture Cargo.lock SHA-256: {hashlib.sha256(fixture_lock).hexdigest()}", + "Fixture registry dependencies verified as an exact subset of the firmware lock:", + *[ + f" {name} {version} source={source} checksum={checksum}" + for source, name, version, checksum in packages + ], + ] + print("\n".join(provenance)) + results = [] + for mode in ["used", "unused", "unextracted"]: + use_b = mode != "unextracted" + rust_call = ( + "assert!(std::hint::black_box(error_id_b::fixture_b()) >= 65401);" + if use_b + else "" + ) + native_call = "|| fixture_b() < 65401" if use_b else "" + (work / "app/src/main.rs").write_text(f""" +extern crate error_id_b; +fn main() {{ + assert_eq!(std::hint::black_box(error_id_a::fixture_a()), 65401); + {rust_call} +}} +""") + (work / "main.cpp").write_text(f""" +#include +extern "C" uint16_t fixture_a(); +extern "C" uint16_t fixture_b(); +int main() {{ return fixture_a() != 65401 {native_call}; }} +""") + for duplicate in [False, True]: + label = f"{mode}-{'duplicate' if duplicate else 'unique'}" + features = ["error-id-b/duplicate"] if duplicate else [] + if mode != "used": + features += ["error-id-a/unused", "error-id-b/unused"] + target = work / "target" / label + cargo = [ + "cargo", + "+1.90.0", + "build", + "--locked", + "--offline", + "--release", + "--target", + host, + "--target-dir", + str(target), + ] + if features: + cargo += ["--features", ",".join(features)] + # Each archive must build independently before linking them together. + archives = run(cargo + ["-p", "error-id-a", "-p", "error-id-b"], work) + require_success(archives) + release = target / host / "release" + native = run( + [ + "c++", + str(work / "main.cpp"), + str(release / "liberror_id_a.a"), + str(release / "liberror_id_b.a"), + "-ldl", + "-lpthread", + "-lm", + "-o", + str(release / "native-app"), + ], + work, + ) + rust = run(cargo + ["-p", "error-id-app"], work) + for kind, result, binary in [ + ("staticlib", native, release / "native-app"), + ("rlib", rust, release / "error-id-app"), + ]: + (work / f"{label}-{kind}.log").write_text(result.stdout + result.stderr) + if not duplicate: + require_success(result) + elif (use_b or kind == "rlib") and result.returncode == 0: + raise RuntimeError(f"{label} {kind}: duplicate unexpectedly linked") + if result.returncode == 0: + require_success(run([str(binary)], work)) + outcome = "linked and ran" + else: + if "__kaptan_error_id_65401" not in result.stderr: + raise RuntimeError(result.stderr) + outcome = "duplicate ID rejected" + results.append(f"{label} {kind}: {outcome}") + print("\n".join(results)) + (work / "results.txt").write_text( + version.stdout + "\n".join(provenance + results) + "\n" + ) + + +if __name__ == "__main__": + main() diff --git a/firmware/libs/kaptan-err-reportable/src/ingress.rs b/firmware/libs/kaptan-err-reportable/src/ingress.rs index 96dee10..4ef5e43 100644 --- a/firmware/libs/kaptan-err-reportable/src/ingress.rs +++ b/firmware/libs/kaptan-err-reportable/src/ingress.rs @@ -78,6 +78,54 @@ mod tests { use super::ErrorIngress; use crate::ErrorId; + #[test] + fn concurrent_publication_and_take_preserve_complete_unique_records() { + let ingress = ErrorIngress::new(); + let start = std::sync::Barrier::new(3); + let mut records = std::thread::scope(|scope| { + let ingress = &ingress; + let start = &start; + let producers: [_; 2] = core::array::from_fn(|producer| { + scope.spawn(move || { + start.wait(); + for sequence in 0..8 { + ingress.publish( + ErrorId::new(1000 + (producer * 8 + sequence) as u16), + ["left", "right"][producer], + ); + std::thread::yield_now(); + } + }) + }); + let consumer = scope.spawn(move || { + start.wait(); + let mut records = std::vec::Vec::new(); + for _ in 0..64 { + records.extend(ingress.take()); + std::thread::yield_now(); + } + records + }); + for producer in producers { + producer.join().unwrap(); + } + consumer.join().unwrap() + }); + records.extend(ingress.take()); + assert!(ingress.take().is_none()); + assert!(!records.is_empty()); + + // Contention may discard publications. Every retained record must be + // one complete publication, and it may be consumed only once. + let mut seen = [false; 16]; + for record in records { + let index = usize::from(record.id().checked_sub(1000).unwrap()); + assert!(index < seen.len()); + assert_eq!(record.raised_at(), ["left", "right"][index / 8]); + assert!(!core::mem::replace(&mut seen[index], true)); + } + } + #[test] fn retains_the_first_id_and_location_until_consumed() { let ingress = ErrorIngress::new(); diff --git a/firmware/libs/kaptan-err-reportable/src/lib.rs b/firmware/libs/kaptan-err-reportable/src/lib.rs index 475e0ba..16b37f6 100644 --- a/firmware/libs/kaptan-err-reportable/src/lib.rs +++ b/firmware/libs/kaptan-err-reportable/src/lib.rs @@ -1,8 +1,5 @@ //! Stable reportable firmware errors with bounded diagnostic ingress. //! -//! This crate owns error identity and ingress. It contains no logging levels, -//! filtering, MAVLink, board, filesystem, or clock dependency. -//! //! `#[propagate]` turns an annotated function into a reporting point. When a //! reportable error leaves that function, the macro makes one reporting //! attempt. Nested annotated callers would therefore attempt to report the diff --git a/firmware/libs/kaptan-log/src/facade.rs b/firmware/libs/kaptan-log/src/facade.rs index d5c000b..91781e2 100644 --- a/firmware/libs/kaptan-log/src/facade.rs +++ b/firmware/libs/kaptan-log/src/facade.rs @@ -71,18 +71,18 @@ impl LogIngress { } fn drain_one(&self, consume: impl FnOnce(&LogRecord) -> R) -> Option { - self.with_state(|entries, head, len| { - if *len == 0 { - return None; - } - let record = entries[*head].as_ref()?; - let result = consume(record); - entries[*head] = None; - *head = (*head + 1) % N; - *len -= 1; - Some(result) - }) - .flatten() + let record = self + .with_state(|entries, head, len| { + if *len == 0 { + return None; + } + let record = entries[*head].take(); + *head = (*head + 1) % N; + *len -= 1; + record + }) + .flatten()?; + Some(consume(&record)) } fn with_state( @@ -116,8 +116,9 @@ pub fn publish(level: Level, arguments: fmt::Arguments<'_>) { /// Visits and removes the oldest pending log event. /// -/// The callback runs during the ingress's one nonblocking ownership attempt; -/// it should perform only bounded composition-level sink fanout. +/// The record is removed and exclusive ingress access is released before the +/// callback runs. Reentrant logging can use the freed slot. If the callback +/// unwinds, this record is consumed and other pending records remain available. #[inline] pub fn drain_one(consume: impl FnOnce(&LogRecord) -> R) -> Option { GLOBAL_INGRESS.drain_one(consume) @@ -138,6 +139,70 @@ mod tests { core::str::from_utf8(&text.bytes()[..usize::from(text.byte_length())]).unwrap() } + #[test] + fn concurrent_publication_and_drain_preserve_complete_unique_records() { + let ingress = LogIngress::<2>::new(); + // A critical record cannot be evicted. This guarantees one observation + // even if contention rejects every concurrent publication. + ingress.publish(Level::Error, core::format_args!("initial")); + let start = std::sync::Barrier::new(3); + let mut records = std::thread::scope(|scope| { + let ingress = &ingress; + let start = &start; + let producers: [_; 2] = core::array::from_fn(|producer| { + scope.spawn(move || { + start.wait(); + for sequence in 0..8 { + ingress.publish( + [Level::Info, Level::Error][producer], + core::format_args!("{producer}:{sequence}"), + ); + std::thread::yield_now(); + } + }) + }); + let consumer = scope.spawn(move || { + start.wait(); + let mut records = std::vec::Vec::new(); + for _ in 0..64 { + records.extend(ingress.drain_one(|record| *record)); + std::thread::yield_now(); + } + records + }); + for producer in producers { + producer.join().unwrap(); + } + consumer.join().unwrap() + }); + for _ in 0..2 { + records.extend(ingress.drain_one(|record| *record)); + } + assert!(ingress.drain_one(|_| ()).is_none()); + + // Contention and critical replacement may discard publications. A + // delivered record must retain its own level and text without repeats. + let mut seen = [false; 16]; + let mut initial_seen = false; + for record in records { + if message(&record) == "initial" { + assert_eq!(record.level(), Level::Error); + assert!(!core::mem::replace(&mut initial_seen, true)); + continue; + } + let (producer, sequence) = message(&record).split_once(':').unwrap(); + let producer: usize = producer.parse().unwrap(); + let sequence: usize = sequence.parse().unwrap(); + assert!(producer < 2 && sequence < 8); + assert_eq!(record.level(), [Level::Info, Level::Error][producer]); + assert!(!core::mem::replace( + &mut seen[producer * 8 + sequence], + true + )); + } + assert!(initial_seen); + } + #[test] fn every_macro_produces_the_same_log_record_kind() { let _guard = GLOBAL_INGRESS_TEST @@ -213,4 +278,48 @@ mod tests { Some(()) ); } + + #[test] + fn callback_can_publish_and_drain_reentrantly() { + let ingress = LogIngress::<1>::new(); + ingress.publish(Level::Info, core::format_args!("outer")); + assert_eq!( + ingress.drain_one(|record| { + assert!(!ingress.busy.load(Ordering::Relaxed)); + ingress.publish(Level::Info, core::format_args!("inner")); + assert_eq!( + ingress.drain_one(|inner| assert_eq!(message(inner), "inner")), + Some(()) + ); + assert_eq!(message(record), "outer"); + }), + Some(()) + ); + assert!(ingress.drain_one(|_| ()).is_none()); + } + + #[test] + fn callback_unwind_leaves_ingress_free_and_other_records_pending() { + let ingress = LogIngress::<2>::new(); + ingress.publish(Level::Info, core::format_args!("consumed")); + ingress.publish(Level::Error, core::format_args!("pending")); + let result = std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| { + ingress.drain_one(|record| { + assert_eq!(message(record), "consumed"); + panic!("consumer failed"); + }); + })); + assert!(result.is_err()); + assert!(!ingress.busy.load(Ordering::Relaxed)); + ingress.publish(Level::Info, core::format_args!("new")); + assert_eq!( + ingress.drain_one(|record| assert_eq!(message(record), "pending")), + Some(()) + ); + assert_eq!( + ingress.drain_one(|record| assert_eq!(message(record), "new")), + Some(()) + ); + assert!(ingress.drain_one(|_| ()).is_none()); + } } diff --git a/firmware/libs/kaptan-log/src/lib.rs b/firmware/libs/kaptan-log/src/lib.rs index 6220b43..fce1d71 100644 --- a/firmware/libs/kaptan-log/src/lib.rs +++ b/firmware/libs/kaptan-log/src/lib.rs @@ -1,12 +1,11 @@ //! Bounded, transport-neutral runtime logging for Kaptan. //! -//! This crate deliberately contains no MAVLink, board, filesystem, or clock -//! dependency. Its sole configuration coupling is compile-time enum metadata -//! for [`LevelFilter`]. Flight code reports bounded events to -//! independently filtered sink queues; a platform-owned adapter may later -//! encode one queue for a link. -//! Reporting is observational and must never influence flight control or -//! actuator authority. +//! Each sink filters and queues events for a transport adapter. Logging must +//! not affect flight-control decisions or actuator authority. +//! +//! Text overflow stops formatting that propagates `core::fmt::Error`. Custom +//! `Display` implementations may ignore that error or perform arbitrary work, +//! so fixed storage and queue bounds do not establish a universal time bound. #![no_std] diff --git a/firmware/libs/kaptan-log/src/text.rs b/firmware/libs/kaptan-log/src/text.rs index b057ff1..140ce03 100644 --- a/firmware/libs/kaptan-log/src/text.rs +++ b/firmware/libs/kaptan-log/src/text.rs @@ -27,6 +27,9 @@ impl LogText { } /// Formats one message without allocation. + /// + /// Overflow stops formatters that propagate `fmt::Error`. A custom `Display` + /// implementation can ignore that error or do unbounded work of its own. pub(crate) fn from_arguments(arguments: fmt::Arguments<'_>) -> Self { let mut text = Self::new(); let _ = fmt::write(&mut text, arguments); @@ -58,6 +61,9 @@ impl LogText { impl fmt::Write for LogText { fn write_str(&mut self, message: &str) -> fmt::Result { + if self.is_truncated() { + return Err(fmt::Error); + } let remaining = MAXIMUM_LOG_TEXT_BYTES - usize::from(self.length); let prefix = if message.len() <= remaining { message.len() @@ -73,13 +79,18 @@ impl fmt::Write for LogText { let used = usize::from(self.length); self.bytes[used..used + prefix].copy_from_slice(&message.as_bytes()[..prefix]); self.length = (used + prefix) as u8; - Ok(()) + if self.is_truncated() { + Err(fmt::Error) + } else { + Ok(()) + } } } #[cfg(test)] mod tests { use super::{LogText, MAXIMUM_LOG_TEXT_BYTES}; + use core::fmt::{self, Write}; #[test] fn truncates_only_at_utf8_boundaries() { @@ -95,4 +106,61 @@ mod tests { MAXIMUM_LOG_TEXT_BYTES - 1 ); } + + #[test] + fn exact_multibyte_fit_is_not_truncated() { + let input = "x".repeat(MAXIMUM_LOG_TEXT_BYTES - 2) + "é"; + let mut text = LogText::new(); + assert_eq!(text.write_str(&input), Ok(())); + assert_eq!(text.write_str(""), Ok(())); + assert!(!text.is_truncated()); + assert_eq!(text.bytes().as_slice(), input.as_bytes()); + assert_eq!(text.write_str("a"), Err(fmt::Error)); + assert!(text.is_truncated()); + assert_eq!(text.bytes().as_slice(), input.as_bytes()); + } + + #[test] + fn overflow_latches_even_if_a_formatter_ignores_the_error() { + struct Fragments; + impl fmt::Display for Fragments { + fn fmt(&self, formatter: &mut fmt::Formatter<'_>) -> fmt::Result { + formatter.write_str(&"x".repeat(MAXIMUM_LOG_TEXT_BYTES - 3))?; + formatter.write_str("é")?; + let _ = formatter.write_str("🙂"); + let _ = formatter.write_str("a"); + Ok(()) + } + } + let text = LogText::from_arguments(format_args!("{Fragments}")); + let expected = "x".repeat(MAXIMUM_LOG_TEXT_BYTES - 3) + "é"; + assert!(text.is_truncated()); + assert_eq!( + &text.bytes()[..usize::from(text.byte_length())], + expected.as_bytes() + ); + assert_eq!(text.bytes()[MAXIMUM_LOG_TEXT_BYTES - 1], 0); + } + + #[test] + fn large_standard_padding_stops_at_the_first_overflow() { + struct CountWrites { + text: LogText, + writes: usize, + } + impl fmt::Write for CountWrites { + fn write_str(&mut self, message: &str) -> fmt::Result { + self.writes += 1; + self.text.write_str(message) + } + } + let mut output = CountWrites { + text: LogText::new(), + writes: 0, + }; + assert_eq!(write!(output, "{:>65535}", "end"), Err(fmt::Error)); + assert!(output.writes <= MAXIMUM_LOG_TEXT_BYTES + 1); + assert!(output.text.is_truncated()); + assert_eq!(output.text.bytes(), &[b' '; MAXIMUM_LOG_TEXT_BYTES]); + } } diff --git a/flake.nix b/flake.nix index f2689d4..bd8594c 100644 --- a/flake.nix +++ b/flake.nix @@ -22,6 +22,7 @@ default = pkgs.mkShell { packages = [ pkgs.rustup + pkgs.gcc pkgs.dfu-util pkgs.mdbook pkgs.ripgrep