diff --git a/.travis.yml b/.travis.yml index 65064f3..32f2dc3 100644 --- a/.travis.yml +++ b/.travis.yml @@ -1,21 +1,13 @@ language: rust -addons: - apt: - packages: - - qemu-system-arm - matrix: include: - rust: beta - -matrix: - include: - rust: nightly install: - bash ci/install.sh - - export PATH="$PATH:$PWD/gcc/bin" + - export PATH="$PATH:$PWD/gcc/bin:$PWD/qemu" script: - bash ci/script.sh diff --git a/ci/install.sh b/ci/install.sh index 62336d0..501f8f5 100644 --- a/ci/install.sh +++ b/ci/install.sh @@ -16,6 +16,10 @@ main() { curl -L https://developer.arm.com/-/media/Files/downloads/gnu-rm/7-2018q2/gcc-arm-none-eabi-7-2018-q2-update-linux.tar.bz2?revision=bc2c96c0-14b5-4bb4-9f18-bceb4050fee7?product=GNU%20Arm%20Embedded%20Toolchain,64-bit,,Linux,7-2018-q2-update | tar --strip-components=1 -C gcc -xj + mkdir qemu + curl -L https://github.com/japaric/qemu-bin/raw/master/14.04/qemu-system-arm-2.12.0 > qemu/qemu-system-arm + chmod +x qemu/qemu-system-arm + rustup component add llvm-tools-preview curl -LSfs https://japaric.github.io/trust/install.sh | \ diff --git a/ci/logging/app/.cargo/config b/ci/logging/app/.cargo/config new file mode 100644 index 0000000..d0790fa --- /dev/null +++ b/ci/logging/app/.cargo/config @@ -0,0 +1,6 @@ +[target.thumbv7m-none-eabi] +runner = "qemu-system-arm -cpu cortex-m3 -machine lm3s6965evb -nographic -semihosting-config enable=on,target=native -kernel" +rustflags = ["-C", "link-arg=-Tlink.x"] + +[build] +target = "thumbv7m-none-eabi" \ No newline at end of file diff --git a/ci/logging/app/Cargo.toml b/ci/logging/app/Cargo.toml new file mode 100644 index 0000000..3519b40 --- /dev/null +++ b/ci/logging/app/Cargo.toml @@ -0,0 +1,13 @@ +[package] +authors = ["Jorge Aparicio "] +edition = "2018" +name = "app" +version = "0.1.0" + +[dependencies] +cortex-m-semihosting = "0.3.1" +rt = { path = "../rt" } + +[profile.release] +codegen-units = 1 +lto = true \ No newline at end of file diff --git a/ci/logging/app/dev.objdump b/ci/logging/app/dev.objdump new file mode 100644 index 0000000..327fffd --- /dev/null +++ b/ci/logging/app/dev.objdump @@ -0,0 +1,2 @@ +00001fe1 l .rodata 00000001 Goodbye +00001fe0 l .rodata 00000001 Hello, world! diff --git a/ci/logging/app/dev.out b/ci/logging/app/dev.out new file mode 100644 index 0000000..b8f2736 --- /dev/null +++ b/ci/logging/app/dev.out @@ -0,0 +1,2 @@ +0x1fe0 +0x1fe1 diff --git a/ci/logging/app/release.objdump b/ci/logging/app/release.objdump new file mode 100644 index 0000000..06b0150 --- /dev/null +++ b/ci/logging/app/release.objdump @@ -0,0 +1,2 @@ +00000a7d l .rodata 00000001 Goodbye +00000a7c l .rodata 00000001 Hello, world! diff --git a/ci/logging/app/release.out b/ci/logging/app/release.out new file mode 100644 index 0000000..4108d8f --- /dev/null +++ b/ci/logging/app/release.out @@ -0,0 +1,2 @@ +0xa7c +0xa7d diff --git a/ci/logging/app/src/main.rs b/ci/logging/app/src/main.rs new file mode 100644 index 0000000..a0f15ee --- /dev/null +++ b/ci/logging/app/src/main.rs @@ -0,0 +1,27 @@ +#![no_main] +#![no_std] + +use core::fmt::Write; +use cortex_m_semihosting::{debug, hio}; + +use rt::entry; + +entry!(main); + +fn main() -> ! { + let mut hstdout = hio::hstdout().unwrap(); + + #[export_name = "Hello, world!"] + static A: u8 = 0; + + writeln!(hstdout, "{:#x}", &A as *const u8 as usize); + + #[export_name = "Goodbye"] + static B: u8 = 0; + + writeln!(hstdout, "{:#x}", &B as *const u8 as usize); + + debug::exit(debug::EXIT_SUCCESS); + + loop {} +} diff --git a/ci/logging/app2/.cargo/config b/ci/logging/app2/.cargo/config new file mode 100644 index 0000000..f28460c --- /dev/null +++ b/ci/logging/app2/.cargo/config @@ -0,0 +1,9 @@ +[target.thumbv7m-none-eabi] +runner = "qemu-system-arm -cpu cortex-m3 -machine lm3s6965evb -nographic -semihosting-config enable=on,target=native -kernel" +rustflags = [ + "-C", "link-arg=-Tlink.x", + "-C", "link-arg=-Tlog.x", # <- NEW! +] + +[build] +target = "thumbv7m-none-eabi" \ No newline at end of file diff --git a/ci/logging/app2/Cargo.toml b/ci/logging/app2/Cargo.toml new file mode 100644 index 0000000..3519b40 --- /dev/null +++ b/ci/logging/app2/Cargo.toml @@ -0,0 +1,13 @@ +[package] +authors = ["Jorge Aparicio "] +edition = "2018" +name = "app" +version = "0.1.0" + +[dependencies] +cortex-m-semihosting = "0.3.1" +rt = { path = "../rt" } + +[profile.release] +codegen-units = 1 +lto = true \ No newline at end of file diff --git a/ci/logging/app2/dev.objdump b/ci/logging/app2/dev.objdump new file mode 100644 index 0000000..ce3cb67 --- /dev/null +++ b/ci/logging/app2/dev.objdump @@ -0,0 +1,2 @@ +00000001 l .log 00000001 Goodbye +00000000 l .log 00000001 Hello, world! diff --git a/ci/logging/app2/dev.out b/ci/logging/app2/dev.out new file mode 100644 index 0000000..6350475 --- /dev/null +++ b/ci/logging/app2/dev.out @@ -0,0 +1 @@ +0001 diff --git a/ci/logging/app2/log.x b/ci/logging/app2/log.x new file mode 100644 index 0000000..84f22f3 --- /dev/null +++ b/ci/logging/app2/log.x @@ -0,0 +1,6 @@ +SECTIONS +{ + .log 0 (INFO) : { + *(.log); + } +} diff --git a/ci/logging/app2/src/main.rs b/ci/logging/app2/src/main.rs new file mode 100644 index 0000000..3b00eb6 --- /dev/null +++ b/ci/logging/app2/src/main.rs @@ -0,0 +1,30 @@ +#![no_main] +#![no_std] + +use cortex_m_semihosting::{debug, hio}; + +use rt::entry; + +entry!(main); + +fn main() -> ! { + let mut hstdout = hio::hstdout().unwrap(); + + #[export_name = "Hello, world!"] + #[link_section = ".log"] // <- NEW! + static A: u8 = 0; + + let address = &A as *const u8 as usize as u8; + hstdout.write_all(&[address]).unwrap(); // <- CHANGED! + + #[export_name = "Goodbye"] + #[link_section = ".log"] // <- NEW! + static B: u8 = 0; + + let address = &B as *const u8 as usize as u8; + hstdout.write_all(&[address]).unwrap(); // <- CHANGED! + + debug::exit(debug::EXIT_SUCCESS); + + loop {} +} diff --git a/ci/logging/app3/.cargo b/ci/logging/app3/.cargo new file mode 120000 index 0000000..2a3ea18 --- /dev/null +++ b/ci/logging/app3/.cargo @@ -0,0 +1 @@ +../app2/.cargo \ No newline at end of file diff --git a/ci/logging/app3/Cargo.toml b/ci/logging/app3/Cargo.toml new file mode 100644 index 0000000..f23ea58 --- /dev/null +++ b/ci/logging/app3/Cargo.toml @@ -0,0 +1,10 @@ +[package] +authors = ["Jorge Aparicio "] +edition = "2018" +name = "app" +version = "0.1.0" + +[dependencies] +cortex-m-semihosting = "0.3.1" +log = { path = "../log" } +rt = { path = "../rt" } diff --git a/ci/logging/app3/dev.objdump b/ci/logging/app3/dev.objdump new file mode 100644 index 0000000..ce3cb67 --- /dev/null +++ b/ci/logging/app3/dev.objdump @@ -0,0 +1,2 @@ +00000001 l .log 00000001 Goodbye +00000000 l .log 00000001 Hello, world! diff --git a/ci/logging/app3/dev.out b/ci/logging/app3/dev.out new file mode 100644 index 0000000..6350475 --- /dev/null +++ b/ci/logging/app3/dev.out @@ -0,0 +1 @@ +0001 diff --git a/ci/logging/app3/src/main.rs b/ci/logging/app3/src/main.rs new file mode 100644 index 0000000..0107121 --- /dev/null +++ b/ci/logging/app3/src/main.rs @@ -0,0 +1,37 @@ +#![no_main] +#![no_std] + +use cortex_m_semihosting::{ + debug, + hio::{self, HStdout}, +}; + +use log::{log, Log}; +use rt::entry; + +struct Logger { + hstdout: HStdout, +} + +impl Log for Logger { + type Error = (); + + fn log(&mut self, address: u8) -> Result<(), ()> { + self.hstdout.write_all(&[address]) + } +} + +entry!(main); + +fn main() -> ! { + let hstdout = hio::hstdout().unwrap(); + let mut logger = Logger { hstdout }; + + log!(logger, "Hello, world!"); + + log!(logger, "Goodbye"); + + debug::exit(debug::EXIT_SUCCESS); + + loop {} +} diff --git a/ci/logging/app4/.cargo b/ci/logging/app4/.cargo new file mode 120000 index 0000000..2a3ea18 --- /dev/null +++ b/ci/logging/app4/.cargo @@ -0,0 +1 @@ +../app2/.cargo \ No newline at end of file diff --git a/ci/logging/app4/Cargo.toml b/ci/logging/app4/Cargo.toml new file mode 100644 index 0000000..44b41ca --- /dev/null +++ b/ci/logging/app4/Cargo.toml @@ -0,0 +1,10 @@ +[package] +authors = ["Jorge Aparicio "] +edition = "2018" +name = "app" +version = "0.1.0" + +[dependencies] +cortex-m-semihosting = "0.3.1" +log = { path = "../log2" } +rt = { path = "../rt" } diff --git a/ci/logging/app4/dev.objdump b/ci/logging/app4/dev.objdump new file mode 100644 index 0000000..8a4f1da --- /dev/null +++ b/ci/logging/app4/dev.objdump @@ -0,0 +1,3 @@ +00000000 l .log 00000001 Goodbye +00000001 l .log 00000001 Hello, world! +00000001 .log 00000000 __log_warning_start__ diff --git a/ci/logging/app4/dev.out b/ci/logging/app4/dev.out new file mode 100644 index 0000000..e199843 --- /dev/null +++ b/ci/logging/app4/dev.out @@ -0,0 +1 @@ +0100 diff --git a/ci/logging/app4/src/main.rs b/ci/logging/app4/src/main.rs new file mode 100644 index 0000000..66cb9ab --- /dev/null +++ b/ci/logging/app4/src/main.rs @@ -0,0 +1,37 @@ +#![no_main] +#![no_std] + +use cortex_m_semihosting::{ + debug, + hio::{self, HStdout}, +}; + +use log::{error, warn, Log}; +use rt::entry; + +entry!(main); + +fn main() -> ! { + let hstdout = hio::hstdout().unwrap(); + let mut logger = Logger { hstdout }; + + warn!(logger, "Hello, world!"); // <- CHANGED! + + error!(logger, "Goodbye"); // <- CHANGED! + + debug::exit(debug::EXIT_SUCCESS); + + loop {} +} + +struct Logger { + hstdout: HStdout, +} + +impl Log for Logger { + type Error = (); + + fn log(&mut self, address: u8) -> Result<(), ()> { + self.hstdout.write_all(&[address]) + } +} diff --git a/ci/logging/log/Cargo.toml b/ci/logging/log/Cargo.toml new file mode 100644 index 0000000..e67d724 --- /dev/null +++ b/ci/logging/log/Cargo.toml @@ -0,0 +1,7 @@ +[package] +name = "log" +version = "0.1.0" +authors = ["Jorge Aparicio "] +edition = "2018" + +[dependencies] diff --git a/ci/logging/log/build.rs b/ci/logging/log/build.rs new file mode 100644 index 0000000..91397e0 --- /dev/null +++ b/ci/logging/log/build.rs @@ -0,0 +1,12 @@ +use std::{env, error::Error, fs::File, io::Write, path::PathBuf}; + +fn main() -> Result<(), Box> { + // Put the linker script somewhere the linker can find it + let out = PathBuf::from(env::var("OUT_DIR")?); + + File::create(out.join("log.x"))?.write_all(include_bytes!("log.x"))?; + + println!("cargo:rustc-link-search={}", out.display()); + + Ok(()) +} diff --git a/ci/logging/log/log.x b/ci/logging/log/log.x new file mode 100644 index 0000000..84f22f3 --- /dev/null +++ b/ci/logging/log/log.x @@ -0,0 +1,6 @@ +SECTIONS +{ + .log 0 (INFO) : { + *(.log); + } +} diff --git a/ci/logging/log/src/lib.rs b/ci/logging/log/src/lib.rs new file mode 100644 index 0000000..78afdd0 --- /dev/null +++ b/ci/logging/log/src/lib.rs @@ -0,0 +1,18 @@ +#![no_std] + +pub trait Log { + type Error; + + fn log(&mut self, address: u8) -> Result<(), Self::Error>; +} + +#[macro_export] +macro_rules! log { + ($logger:expr, $string:expr) => {{ + #[export_name = $string] + #[link_section = ".log"] + static SYMBOL: u8 = 0; + + $crate::Log::log(&mut $logger, &SYMBOL as *const u8 as usize as u8) + }}; +} diff --git a/ci/logging/log2/Cargo.toml b/ci/logging/log2/Cargo.toml new file mode 100644 index 0000000..e67d724 --- /dev/null +++ b/ci/logging/log2/Cargo.toml @@ -0,0 +1,7 @@ +[package] +name = "log" +version = "0.1.0" +authors = ["Jorge Aparicio "] +edition = "2018" + +[dependencies] diff --git a/ci/logging/log2/build.rs b/ci/logging/log2/build.rs new file mode 120000 index 0000000..bdb2804 --- /dev/null +++ b/ci/logging/log2/build.rs @@ -0,0 +1 @@ +../log/build.rs \ No newline at end of file diff --git a/ci/logging/log2/log.x b/ci/logging/log2/log.x new file mode 100644 index 0000000..474db6a --- /dev/null +++ b/ci/logging/log2/log.x @@ -0,0 +1,8 @@ +SECTIONS +{ + .log 0 (INFO) : { + *(.log.error); + __log_warning_start__ = .; + *(.log.warning); + } +} diff --git a/ci/logging/log2/src/lib.rs b/ci/logging/log2/src/lib.rs new file mode 100644 index 0000000..b67d96b --- /dev/null +++ b/ci/logging/log2/src/lib.rs @@ -0,0 +1,31 @@ +#![no_std] + +pub trait Log { + type Error; + + fn log(&mut self, address: u8) -> Result<(), Self::Error>; +} + +/// Logs messages at the ERROR log level +#[macro_export] +macro_rules! error { + ($logger:expr, $string:expr) => {{ + #[export_name = $string] + #[link_section = ".log.error"] // <- CHANGED! + static SYMBOL: u8 = 0; + + $crate::Log::log(&mut $logger, &SYMBOL as *const u8 as usize as u8) + }}; +} + +/// Logs messages at the WARNING log level +#[macro_export] +macro_rules! warn { + ($logger:expr, $string:expr) => {{ + #[export_name = $string] + #[link_section = ".log.warning"] // <- CHANGED! + static SYMBOL: u8 = 0; + + $crate::Log::log(&mut $logger, &SYMBOL as *const u8 as usize as u8) + }}; +} diff --git a/ci/logging/rt b/ci/logging/rt new file mode 120000 index 0000000..82beb3e --- /dev/null +++ b/ci/logging/rt @@ -0,0 +1 @@ +../exceptions/rt \ No newline at end of file diff --git a/ci/script.sh b/ci/script.sh index a94a4e6..cfed5e8 100644 --- a/ci/script.sh +++ b/ci/script.sh @@ -130,6 +130,70 @@ main() { popd popd + + # # Logging with symbols + pushd logging + + # check that the ~output~ and disassembly matches + # the output won't exactly match because addresses of static variables won't + # remain the same when the toolchain is updated. Instead we'll that the + # printed address is contained in the output of `cargo objdump -- -t` + pushd app + cargo run > dev.out + cargo objdump --bin app -- -t | grep '\.rodata\s*0*1\b' > dev.objdump + for address in $(cat dev.out); do + grep ${address#0x} dev.objdump + done + + cargo run --release > release.out + cargo objdump --bin app --release -- -t | grep '\.rodata\s*0*1\b' > dev.objdump + for address in $(cat release.out); do + grep ${address#0x} release.objdump + done + + # sanity check the committed files + git checkout dev.out + git checkout dev.objdump + for address in $(cat dev.out); do + grep ${address#0x} dev.objdump + done + + git checkout release.out + git checkout release.objdump + for address in $(cat release.out); do + grep ${address#0x} release.objdump + done + edition_check + popd + + # check that the output and disassembly matches + pushd app2 + diff dev.out \ + <(cargo run | xxd -p) + diff dev.objdump \ + <(cargo objdump --bin app -- -t | grep '\.log') + edition_check + popd + + # check that the output and disassembly matches + pushd app3 + diff dev.out \ + <(cargo run | xxd -p) + diff dev.objdump \ + <(cargo objdump --bin app -- -t | grep '\.log') + edition_check + popd + + # check that the output and disassembly matches + pushd app4 + diff dev.out \ + <(cargo run | xxd -p) + diff dev.objdump \ + <(cargo objdump --bin app -- -t | grep '\.log') + edition_check + popd + + popd } # checks that 2018 idioms are being used diff --git a/src/SUMMARY.md b/src/SUMMARY.md index e2792c2..1adfc15 100644 --- a/src/SUMMARY.md +++ b/src/SUMMARY.md @@ -6,5 +6,6 @@ - [A `main` interface](./main.md) - [Exception handling](./exceptions.md) - [Assembly on stable](./asm.md) +- [Logging with symbols](./logging.md) --- [A note on compiler support](./compiler-support.md) diff --git a/src/logging.md b/src/logging.md new file mode 100644 index 0000000..11689e6 --- /dev/null +++ b/src/logging.md @@ -0,0 +1,422 @@ +# Logging with symbols + +This section will show you how to utilize symbols and the ELF format to achieve +super cheap logging. + +## Arbitrary symbols + +Whenever we needed a stable symbol interface between crates we have mainly used +the `no_mangle` attribute and sometimes the `export_name` attribute. The +`export_name` attribute takes a string which becomes the name of the symbol +whereas `#[no_mangle]` is basically sugar for `#[export_name = ]`. + +Turns out we are not limited to single word names; we can use arbitrary strings, +e.g. sentences, as the argument of the `export_name` attribute. As least when +the output format is ELF anything that doesn't contain a null byte is fine. + +Let's check that out: + +``` console +$ cargo new --lib foo + +$ cat foo/src/lib.rs +``` + +``` rust +#[export_name = "Hello, world!"] +#[used] +static A: u8 = 0; + +#[export_name = "こんにちは"] +#[used] +static B: u8 = 0; +``` + +``` console +$ ( cd foo && cargo nm --lib ) +foo-d26a39c34b4e80ce.3lnzqy0jbpxj4pld.rcgu.o: +0000000000000000 r Hello, world! +0000000000000000 V __rustc_debug_gdb_scripts_section__ +0000000000000000 r こんにちは +``` + +Can you see where this is going? + +## Encoding + +Here's what we'll do: we'll create one `static` variable per log message but +instead of storing the messages *in* the variables we'll store the messages in +the variables' *symbol names*. What we'll log then will not be the contents of +the `static` variables but their addresses. + +As long as the `static` variables are not zero sized each one will have a +different address. What we're doing here is effectively encoding each message +into a unique identifier, which happens to be the variable address. Some part of +the log system will have to decode this id back into the message. + +Let's write some code to illustrate the idea. + +In this example we'll need some way to do I/O so we'll use the +[`cortex-m-semihosting`] crate for that. Semihosting is a technique for having a +target device borrow the host I/O capabilities; the host here usually refers to +the machine that's debugging the target device. In our case, QEMU supports +semihosting out of the box so there's no need for a debugger. On a real device +you'll have other ways to do I/O like a serial port; we use semihosting in this +case because it's the easiest way to do I/O on QEMU. + +[`cortex-m-semihosting`]: https://crates.io/crates/cortex-m-semihosting + +Here's the code + +``` rust +{{#include ../ci/logging/app/src/main.rs}} +``` + +We also make use of the `debug::exit` API to have the program terminate the QEMU +process. This is a convenience so we don't have to manually terminate the QEMU +process. + +And here's the `dependencies` section of the Cargo.toml: + +``` toml +{{#include ../ci/logging/app/Cargo.toml:7:9}} +``` + +Now we can build the program + +``` console +$ cargo build +``` + +To run it we'll have to add the `--semihosting-config` flag to our QEMU +invocation: + +``` console +$ qemu-system-arm \ + -cpu cortex-m3 \ + -machine lm3s6965evb \ + -nographic \ + -semihosting-config enable=on,target=native \ + -kernel target/thumbv7m-none-eabi/debug/app +``` + +``` text +{{#include ../ci/logging/app/dev.out}} +``` + +> **NOTE**: These addresses may not be the ones you get locally because +> addresses of `static` variable are not guaranteed to remain the same when the +> toolchain is changed (e.g. optimizations may have improved). + +Now we have two addresses printed to the console. + +## Decoding + +How do we convert these addresses into strings? The answer is in the symbol +table of the ELF file. + +``` console +$ cargo objdump --bin app -- -t | grep '\.rodata\s*0*1\b' +``` + +``` text +{{#include ../ci/logging/app/dev.objdump}} +$ # first column is the symbol address; last column is the symbol name +``` + +`objdump -t` prints the symbol table. This table contains *all* the symbols but +we are only looking for the ones in the `.rodata` section and whose size is one +byte (our variables have type `u8`). + +It's important to note that the address of the symbols will likely change when +optimizing the program. Let's check that. + +> **PROTIP** You can set `target.thumbv7m-none-eabi.runner` to the long QEMU +> command from before (`qemu-system-arm -cpu (..) -kernel`) in the Cargo +> configuration file (`.cargo/conifg`) to have `cargo run` use that *runner* to +> execute the output binary. + +``` console +$ head -n2 .cargo/config +``` + +``` toml +{{#include ../ci/logging/app/.cargo/config:1:2}} +``` + +``` console +$ cargo run --release + Running `qemu-system-arm -cpu cortex-m3 -machine lm3s6965evb -nographic -semihosting-config enable=on,target=native -kernel target/thumbv7m-none-eabi/release/app` +``` + +``` text +{{#include ../ci/logging/app/release.out}} +``` + +``` console +$ cargo objdump --bin app --release -- -t | grep '\.rodata\s*0*1\b' +``` + +``` text +{{#include ../ci/logging/app/release.objdump}} +``` + +So make sure to always look for the strings in the ELF file you executed. + +Of course, the process of looking up the strings in the ELF file can be automated +using a tool that parses the symbol table (`.symtab` section) contained in the +ELF file. Implementing such tool is out of scope for this book and it's left as +an exercise for the reader. + +## Making it zero cost + +Can we do better? Yes, we can! + +The current implementation places the `static` variables in `.rodata`, which +means they occupy size in Flash even though we never use their contents. Using a +little bit of linker script magic we can make them occupy *zero* space in Flash. + +``` console +$ cat log.x +``` + +``` text +{{#include ../ci/logging/app2/log.x}} +``` + +We'll place the `static` variables in this new output `.log` section. This +linker script will collect all the symbols in the `.log` sections of input +object files and put them in an output `.log` section. We have seen this pattern +in the [Memory layout] chapter. + +[Memory layout]: /memory-layout.html + +The new bit here is the `(INFO)` part; this tells the linker that this section +is a non-allocatable section. Non-allocatable sections are kept in the ELF +binary as metadata but they are not loaded onto the target device. + +We also specified the start address of this output section: the `0` in `.log 0 +(INFO)`. + +The other improvement we can do is switch from formatted I/O (`fmt::Write`) to +binary I/O, that is send the addresses to the host as bytes rather than as +strings. + +Binary serialization can be hard but we'll keep things super simple by +serializing each address as a single byte. With this approach we don't have to +worry about endianness or framing. The downside of this format is that a single +byte can only represent up to 256 different addresses. + +Let's make those changes: + +``` rust +{{#include ../ci/logging/app2/src/main.rs}} +``` + +Before you run this you'll have to append `-Tlog.x` to the arguments passed to +the linker. That can be done in the Cargo configuration file. + +``` console +$ cat .cargo/config +``` + +``` toml +{{#include ../ci/logging/app2/.cargo/config}} +``` + +Now you can run it! Since the output now has a binary format we'll pipe it +through the `xxd` command to reformat it as a hexadecimal string. + +``` console +$ cargo run | xxd -p +``` + +``` text +{{#include ../ci/logging/app2/dev.out}} +``` + +The addresses are `0x00` and `0x01`. Let's now look at the symbol table. + +``` console +$ cargo objdump --bin app -- -t | grep '\.log' +``` + +``` text +{{#include ../ci/logging/app2/dev.objdump}} +``` + +There are our strings. You'll notice that their addresses now start at zero; +this is because we set a start address for the output `.log` section. + +Each variable is 1 byte in size because we are using `u8` as their type. If we +used something like `u16` then all address would be even and we would not be +able to efficiently use all the address space (`0...255`). + +## Packaging it up + +You've noticed that the steps to log a string are always the same so we can +refactor them into a macro that lives in its own crate. Also, we can make the +logging library more reusable by abstracting the I/O part behind a trait. + +``` console +$ cargo new --lib log + +$ cat log/src/lib.rs +``` + +``` rust +{{#include ../ci/logging/log/src/lib.rs}} +``` + +Given that this library depends on the `.log` section it should be its +responsibility to provide the `log.x` linker script so let's make that happen. + +``` console +$ mv log.x ../log/ +``` + +``` console +$ cat ../log/build.rs +``` + +``` rust +{{#include ../ci/logging/log/build.rs}} +``` + +Now we can refactor our application to use the `log!` macro: + +``` console +$ cat src/main.rs +``` + +``` rust +{{#include ../ci/logging/app3/src/main.rs}} +``` + +Don't forget to update the `Cargo.toml` file to depend on the new `log` crate. + +``` console +$ tail -n4 Cargo.toml +``` + +``` toml +{{#include ../ci/logging/app3/Cargo.toml:7:10}} +``` + +``` console +$ cargo run | xxd -p +``` + +``` text +{{#include ../ci/logging/app3/dev.out}} +``` + +``` console +$ cargo objdump --bin app -- -t | grep '\.log' +``` + +``` text +{{#include ../ci/logging/app3/dev.objdump}} +``` + +Same output as before! + +## Bonus: Multiple log levels + +Many logging frameworks provide ways to log messages at different *log levels*. +These log levels convey the severity of the message: "this is an error", "this +is just a warning", etc. These log levels can be used to filter out unimportant +messages when searching for e.g. error messages. + +We can extend our logging library to support log levels without increasing its +footprint. Here's how we'll do that: + +We have a flat address space for the messages: from `0` to `255` (inclusive). To +keep things simple let's say we only want to differentiate between error +messages and warning messages. We can place all the error messages at the +beginning of the address space, and all the warning messages *after* the error +messages. If the decoder knows the address of the first warning message then it +can classify the messages. This idea can be extended to support more than two +log levels. + +Let's test the idea by replacing the `log` macro with two new macros: `error!` +and `warn!`. + +``` console +$ cat ../log/src/lib.rs +``` + +``` rust +{{#include ../ci/logging/log2/src/lib.rs}} +``` + +We distinguish errors from warnings by placing the messages in different link +sections. + +The next thing we have to do is update the linker script to place error messages +before the warning messages. + +``` console +$ cat ../log/log.x +``` + +``` text +{{#include ../ci/logging/log2/log.x}} +``` + +We also give a name, `__log_warning_start__`, to the boundary between the errors +and the warnings. The address of this symbol will be the address of the first +warning message. + +We can now update the application to make use of these new macros. + +``` console +$ cat src/main.rs +``` + +``` rust +{{#include ../ci/logging/app4/src/main.rs}} +``` + +The output won't change much: + +``` console +$ cargo run | xxd -p +``` + +``` text +{{#include ../ci/logging/app4/dev.out}} +``` + +We still get two bytes in the output but the error is given the address 0 and +the warning is given the address 1 even though the warning was logged first. + +Now look at the symbol table. + +``` console +$ cargo objdump --bin app -- -t | grep '\.log' +``` + +``` text +{{#include ../ci/logging/app4/dev.objdump}} +``` + +There's now an extra symbol, `__log_warning_start__`, in the `.log` section. +The address of this symbol is the address of the first warning message. +Symbols with addresses lower than this value are errors, and the rest of symbols +are warnings. + +With an appropriate decoder you could get the following human readable output +from all this information: + +``` text +WARNING Hello, world! +ERROR Goodbye +``` + +--- + +If you liked this section check out the [`stlog`] logging framework which is a +complete implementation of this idea. + +[`stlog`]: https://crates.io/crates/stlog