From 334b6ac678f99ef6d1ecba0d0e5dbcbf3615fd34 Mon Sep 17 00:00:00 2001 From: "Jonathan Pallant (Ferrous Systems)" Date: Thu, 25 Jan 2024 18:18:47 +0000 Subject: [PATCH] Add slides on defmt --- training-slides/src/SUMMARY.md | 1 + training-slides/src/defmt.md | 273 +++++++++++++++++++++++++++++++++ 2 files changed, 274 insertions(+) create mode 100644 training-slides/src/defmt.md diff --git a/training-slides/src/SUMMARY.md b/training-slides/src/SUMMARY.md index 967ced49..c7214ca7 100644 --- a/training-slides/src/SUMMARY.md +++ b/training-slides/src/SUMMARY.md @@ -81,6 +81,7 @@ Topics about using Rust on ARM Cortex-M Microcontrollers (and similar). Requires * [Writing Drivers](./writing-drivers.md) * [The Embedded HAL and its implementations](./embedded-hals.md) * [Board Support Crates](./board-support.md) +* [Using defmt](./defmt.md) ## Under development diff --git a/training-slides/src/defmt.md b/training-slides/src/defmt.md new file mode 100644 index 00000000..7c8d38b2 --- /dev/null +++ b/training-slides/src/defmt.md @@ -0,0 +1,273 @@ +# Using defmt + +--- + +defmt is the *Deferred Formatter* + +## Motivation + +* You have a microcontroller +* You want to know what it is doing + +## Classical Approach + +* Set up a UART, +* have a function that writes logs to the UART, and +* instrument your code with logger calls. + +```c +#define INFO(msg, ...) do { \ + if (g_level >= LEVEL_INFO) { \ + fprintf(g_uart, "INFO: " msg, __VA_ARGS__ ) \ + } \ +} while(0) + +INFO("received %u bytes", rx_bytes); +``` + +## Downsides + +* Code size - where do the strings live? +* Waiting for the UART + +## An idea + +* Who actually needs the strings? +* Your serial terminal +* Which is on your laptop... + +--- + +Do the logging strings even need to be in Flash? + +## defmt + +* Deferred Formatting +* Strings are *interned* into a .defmt section + * Is in the ELF file + * Is not in Flash +* Arguments are packed in binary format +* Tools to reconstruct log messages on the host side + +## Benefits + +* Uses less flash space +* Less data to transfer over the wire + +## Downsides + +* Now you need a special viewer tool +* Which needs the *exact* ELF file your chip is running + +## Example + +```rust ignore +let rx_bytes = 300u16; +defmt::error!("received {=u16} bytes", rx_bytes); +``` + +

 

+ +This will transmit just: `[3, 44, 1]` + +Note: + +The string index we give here as `3`, and `44, 1` is 300 encoded as +little-endian bytes. + +## Type Hints + +The braces can contain `{[pos][=Type][:Display]}`: + +* `pos`: a numeric argument position (e.g. `0`) +* `Type`: a type hint +* `Display`: a display hint + +## More Examples + +```rust ignore +defmt::info!("enabled: {=bool}, ready: {=bool}", enabled, ready); +// enabled: true, ready: false + +defmt::trace!("{{ X: {0=0..8}, Y: {0=8..16}, Z: {0=16..19} }}", some_bitfield); +// { X: 125, Y: 3, Z: 2 } + +defmt::error!("data = {=[u8]:#02x}", some_byte_slice) +// data = [0x00, 0x01, 0x02, 0x03] +``` + +Note: + +The `x..y` syntax is the bitfield syntax. `[u8]` is the u8 slice syntax, and +`:#02x` means two-digit hex in the alternate (`0x`) style. + +Using type hints can produce a more efficient encoding. + +## Printing structs and enums + +```rust +#[derive(Debug)] +struct Data { + x: [u8; 5], + y: f64 +} + +fn print(data: &Data) { + println!("data = {:?}", data); +} +``` + +## Printing structs and enums with defmt + +```rust ignore +#[derive(defmt::Format)] +struct Data { + x: [u8; 5], + y: f64 +} + +fn print(data: &Data) { + defmt::info!("data = {=?}", data); +} +``` + +Note: + +The `=?` is optional, as it is the default. It means *render this using the +defmt::Format trait*. + +In defmt, there is not `Debug` vs `Display` distinction - it is up to the host +to decide how best to format the values. + +## Optionally enabling defmt + +* If a library uses `defmt::Format`, the application must set up a logger +* Portable libraries don't want this. Instead: + +```rust ignore +#[cfg_attr(feature = "defmt", derive(defmt::Format))] +struct Data { + x: [u8; 5], + y: f64 +} +``` + +## A better transport + +* UART is slow +* Background DMA from a ring-buffer is complicated to set up +* Can we do better? + +## SEGGER RTT + +* *Real Time Transport* +* Dedicated memory area +* Marked with magic numbers +* Can be found and read by your Debug Probe +* Without interrupting the CPU! +* High speed, near-zero-cost byte-pipe + +## defmt-rtt + +* Implement's SEGGER's RTT protocol +* Wired up as a defmt global logger +* Your *binary* just needs to: + +```rust ignore +use defmt_rtt as _; +``` + +Note: + +The `defmt` calls in your libraries are able to find the 'logging sink' created +by the `defmt-rtt` crate though the use of a type in `defmt-rtt` annotated with: + +```rust ignore +#[defmt::global_logger] +``` + +This creates a bunch of `unsafe` `#[no_mangle]` functions, like: + +```rust ignore +#[inline(never)] +#[no_mangle] +unsafe fn _defmt_acquire() { + ::acquire() +} +``` + +## Log Level + +You can control the log level at compile time with an environment variable: + +```text +DEFMT_LOG=info cargo build +``` + +Note: + +Windows users will use different syntax for cmd.exe vs Powershell. + +## Host tools + +* Knurling's `probe-run` was the first +* The `probe-rs`` CLI now has support (recommended) +* Or use `defmt-print` + +## Using probe-rs + +```console +$ probe-rs run --chip nRF52840_xxAA target/thumbv7em-none-eabihf/debug/radio-puzzle-solution + Erasing ✔ [00:00:00] [#########################] 16.00 KiB/16.00 KiB @ 35.52 KiB/s (eta 0s ) + Programming ✔ [00:00:00] [#########################] 16.00 KiB/16.00 KiB @ 49.90 KiB/s (eta 0s ) Finished in 0.79s +0 DEBUG Initializing the board +└─ dk::init @ /Users/jonathan/Documents/ferrous-systems/rust-exercises/nrf52-code/boards/dk/src/lib.rs:208 +1 DEBUG Clocks configured +└─ dk::init @ /Users/jonathan/Documents/ferrous-systems/rust-exercises/nrf52-code/boards/dk/src/lib.rs:219 +``` + +## Customise the format + +```console +$ probe-rs run --chip nRF52840_xxAA ... --log-format "{t} {f}:{l} {L} {s}" + Erasing ✔ [00:00:00] [#########################] 16.00 KiB/16.00 KiB @ 35.52 KiB/s (eta 0s ) + Programming ✔ [00:00:00] [#########################] 16.00 KiB/16.00 KiB @ 49.90 KiB/s (eta 0s ) Finished in 0.79s +0 lib.rs:208 DEBUG Initializing the board +1 lib.rs:219 DEBUG Clocks configured +``` + +## Set it as your runner + +```toml +[target.thumbv7em-none-eabihf] +runner = "probe-rs run --chip nRF52840_xxAA" +``` + +```console +$ cargo run + Finished dev [optimized + debuginfo] target(s) in 0.03s + Running `probe-rs run --chip nRF52840_xxAA target/thumbv7em-none-eabihf/debug/radio-puzzle-solution` + Erasing ✔ [00:00:00] [#########################] 16.00 KiB/16.00 KiB @ 35.52 KiB/s (eta 0s ) + Programming ✔ [00:00:00] [#########################] 16.00 KiB/16.00 KiB @ 49.90 KiB/s (eta 0s ) Finished in 0.79s +0 DEBUG Initializing the board +└─ dk::init @ /Users/jonathan/Documents/ferrous-systems/rust-exercises/nrf52-code/boards/dk/src/lib.rs:208 +1 DEBUG Clocks configured +└─ dk::init @ /Users/jonathan/Documents/ferrous-systems/rust-exercises/nrf52-code/boards/dk/src/lib.rs:219 +``` + +## More info + +There's a book! + + + +## Re-entrancy + +`defmt::info!` (etc) can be called anywhere, even from an interrupt. + +How do you make that safe? + +## Critical Sections + +* defmt-rtt uses the `critical-section` crate +* More on this elsewhere