Skip to content

Commit

Permalink
Merge pull request #125 from ferrous-systems/add-defmt-deck
Browse files Browse the repository at this point in the history
Add slides on defmt
  • Loading branch information
jonathanpallant authored Jan 31, 2024
2 parents 29ef3ea + 334b6ac commit 75b6b3b
Show file tree
Hide file tree
Showing 2 changed files with 274 additions and 0 deletions.
1 change: 1 addition & 0 deletions training-slides/src/SUMMARY.md
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand Down
273 changes: 273 additions & 0 deletions training-slides/src/defmt.md
Original file line number Diff line number Diff line change
@@ -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);
```

<p>&nbsp;<!-- spacer for "run" button --></p>

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() {
<Logger as defmt::Logger>::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!

<https://defmt.ferrous-systems.com>

## 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

0 comments on commit 75b6b3b

Please sign in to comment.