From 88e79dbac6f29c9cc5296eb026eb238cecebc668 Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Mon, 2 Oct 2023 14:38:02 +0200 Subject: [PATCH 01/15] Add `struct defmt_decoder::log::Formatter` --- decoder/src/log/mod.rs | 72 ++++++++++++++++++++++++++++++-- decoder/src/log/stdout_logger.rs | 50 +++++++++++++++------- 2 files changed, 104 insertions(+), 18 deletions(-) diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index 08dd699b..2c47e597 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -10,12 +10,16 @@ mod format; mod json_logger; mod stdout_logger; +use std::fmt; + use log::{Level, LevelFilter, Log, Metadata, Record}; use serde::{Deserialize, Serialize}; -use std::fmt; - -use self::{json_logger::JsonLogger, stdout_logger::StdoutLogger}; +use self::{ + format::LogSegment, + json_logger::JsonLogger, + stdout_logger::{Printer, StdoutLogger}, +}; use crate::Frame; const DEFMT_TARGET_MARKER: &str = "defmt@"; @@ -170,3 +174,65 @@ impl DefmtLoggerInfo { self.has_timestamp } } + +/// Format [DefmtRecord]s according to a `log_format`. +/// +/// The `log_format` makes it possible to customize the defmt output. +/// +/// The `log_format` is specified here: TODO +// TODO: +// - use two Formatter in StdoutLogger instead of the log format +// - add fn format_to_sink +// - specify log format +pub struct Formatter { + format: Vec, +} + +impl Formatter { + pub fn new(log_format: &str) -> Self { + let format = format::parse(log_format) + .unwrap_or_else(|_| panic!("log format is invalid '{log_format}'")); + Self { format } + } + + pub fn format_to_string( + &self, + frame: Frame<'_>, + file: Option<&str>, + line: Option, + module_path: Option<&str>, + ) -> String { + let timestamp = frame + .display_timestamp() + .map(|ts| ts.to_string()) + .unwrap_or_default(); + + let level = frame.level().map(|level| match level { + crate::Level::Trace => Level::Trace, + crate::Level::Debug => Level::Debug, + crate::Level::Info => Level::Info, + crate::Level::Warn => Level::Warn, + crate::Level::Error => Level::Error, + }); + + match format_args!("{}", frame.display_message()) { + args => { + let log_record = &Record::builder() + .args(args) + .module_path(module_path) + .file(file) + .line(line) + .build(); + + let record = DefmtRecord { + log_record, + payload: Payload { level, timestamp }, + }; + + Printer::new_defmt(&record, &self.format) + .format_frame() + .unwrap() + } + } + } +} diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index 0b0997ee..8176b3fd 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -131,7 +131,7 @@ impl StdoutLogger { } /// Printer for `DefmtRecord`s. -struct Printer<'a> { +pub(super) struct Printer<'a> { record: Record<'a>, format: &'a [LogSegment], min_timestamp_width: usize, @@ -146,6 +146,14 @@ impl<'a> Printer<'a> { } } + pub fn new_defmt(record: &'a DefmtRecord<'a>, format: &'a [LogSegment]) -> Self { + Self { + record: Record::Defmt(record), + format, + min_timestamp_width: 0, + } + } + /// Pads the defmt timestamp to take up at least the given number of characters. /// TODO: Remove this, shouldn't be needed now that we have width field support pub fn min_timestamp_width(&mut self, min_timestamp_width: usize) -> &mut Self { @@ -156,25 +164,37 @@ impl<'a> Printer<'a> { /// Prints the formatted log frame to `sink`. pub fn print_frame(&self, sink: &mut W) -> io::Result<()> { for segment in self.format { - let s = match &segment.metadata { - LogMetadata::String(s) => s.to_string(), - LogMetadata::Timestamp => self.build_timestamp(&segment.format), - LogMetadata::FileName => self.build_file_name(&segment.format), - LogMetadata::FilePath => self.build_file_path(&segment.format), - LogMetadata::ModulePath => self.build_module_path(&segment.format), - LogMetadata::LineNumber => self.build_line_number(&segment.format), - LogMetadata::LogLevel => self.build_log_level(&segment.format), - LogMetadata::Log => self.build_log(&segment.format), - LogMetadata::NestedLogSegments(segments) => { - self.build_nested(segments, &segment.format) - } - }; - + let s = self.build_segment(segment); write!(sink, "{s}")?; } writeln!(sink) } + pub(super) fn format_frame(&self) -> Result { + let mut sink = String::new(); + for segment in self.format { + let s = self.build_segment(segment); + write!(sink, "{s}")?; + } + Ok(sink) + } + + fn build_segment(&self, segment: &LogSegment) -> String { + match &segment.metadata { + LogMetadata::String(s) => s.to_string(), + LogMetadata::Timestamp => self.build_timestamp(&segment.format), + LogMetadata::FileName => self.build_file_name(&segment.format), + LogMetadata::FilePath => self.build_file_path(&segment.format), + LogMetadata::ModulePath => self.build_module_path(&segment.format), + LogMetadata::LineNumber => self.build_line_number(&segment.format), + LogMetadata::LogLevel => self.build_log_level(&segment.format), + LogMetadata::Log => self.build_log(&segment.format), + LogMetadata::NestedLogSegments(segments) => { + self.build_nested(segments, &segment.format) + } + } + } + fn build_nested(&self, segments: &[LogSegment], format: &LogFormat) -> String { let mut result = String::new(); for segment in segments { From f2faf1605bd035bbc898b739c8d41f889c4fc22e Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Thu, 28 Sep 2023 15:30:41 +0200 Subject: [PATCH 02/15] Make Printer methods not public --- decoder/src/log/stdout_logger.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index 8176b3fd..13352b8d 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -138,7 +138,7 @@ pub(super) struct Printer<'a> { } impl<'a> Printer<'a> { - pub fn new(record: Record<'a>, format: &'a [LogSegment]) -> Self { + fn new(record: Record<'a>, format: &'a [LogSegment]) -> Self { Self { record, format, @@ -156,7 +156,7 @@ impl<'a> Printer<'a> { /// Pads the defmt timestamp to take up at least the given number of characters. /// TODO: Remove this, shouldn't be needed now that we have width field support - pub fn min_timestamp_width(&mut self, min_timestamp_width: usize) -> &mut Self { + fn min_timestamp_width(&mut self, min_timestamp_width: usize) -> &mut Self { self.min_timestamp_width = min_timestamp_width; self } From 2daf2c598e92650eee4696342fcf74767dd5b109 Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Mon, 2 Oct 2023 14:38:27 +0200 Subject: [PATCH 03/15] Simplify --- decoder/src/log/mod.rs | 41 +++++++++++++++++------------------------ 1 file changed, 17 insertions(+), 24 deletions(-) diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index 2c47e597..401792de 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -31,18 +31,7 @@ pub fn log_defmt( line: Option, module_path: Option<&str>, ) { - let timestamp = frame - .display_timestamp() - .map(|ts| ts.to_string()) - .unwrap_or_default(); - - let level = frame.level().map(|level| match level { - crate::Level::Trace => Level::Trace, - crate::Level::Debug => Level::Debug, - crate::Level::Info => Level::Info, - crate::Level::Warn => Level::Warn, - crate::Level::Error => Level::Error, - }); + let (timestamp, level) = timestamp_and_level_from_frame(&frame); let target = format!( "{}{}", @@ -202,18 +191,7 @@ impl Formatter { line: Option, module_path: Option<&str>, ) -> String { - let timestamp = frame - .display_timestamp() - .map(|ts| ts.to_string()) - .unwrap_or_default(); - - let level = frame.level().map(|level| match level { - crate::Level::Trace => Level::Trace, - crate::Level::Debug => Level::Debug, - crate::Level::Info => Level::Info, - crate::Level::Warn => Level::Warn, - crate::Level::Error => Level::Error, - }); + let (timestamp, level) = timestamp_and_level_from_frame(&frame); match format_args!("{}", frame.display_message()) { args => { @@ -236,3 +214,18 @@ impl Formatter { } } } + +fn timestamp_and_level_from_frame(frame: &Frame<'_>) -> (String, Option) { + let timestamp = frame + .display_timestamp() + .map(|ts| ts.to_string()) + .unwrap_or_default(); + let level = frame.level().map(|level| match level { + crate::Level::Trace => Level::Trace, + crate::Level::Debug => Level::Debug, + crate::Level::Info => Level::Info, + crate::Level::Warn => Level::Warn, + crate::Level::Error => Level::Error, + }); + (timestamp, level) +} From a060524fd05c3445dc56fc0928613664bc1bd53f Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Mon, 2 Oct 2023 14:38:49 +0200 Subject: [PATCH 04/15] Clean up imports --- decoder/src/lib.rs | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/decoder/src/lib.rs b/decoder/src/lib.rs index 7da00bf2..7542eeb8 100644 --- a/decoder/src/lib.rs +++ b/decoder/src/lib.rs @@ -29,13 +29,15 @@ use std::{ }; use byteorder::{ReadBytesExt, LE}; -use decoder::Decoder; use defmt_parser::Level; -use elf2table::parse_impl; -pub use elf2table::{Location, Locations}; -pub use frame::Frame; -pub use stream::StreamDecoder; +use crate::{decoder::Decoder, elf2table::parse_impl}; + +pub use crate::{ + elf2table::{Location, Locations}, + frame::Frame, + stream::StreamDecoder, +}; /// Specifies the origin of a format string #[derive(PartialEq, Eq, Debug)] From ce93caa2e47a9eea9eca8f5b3713351bbee35930 Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Mon, 2 Oct 2023 17:29:39 +0200 Subject: [PATCH 05/15] derive Debug --- decoder/src/log/mod.rs | 1 + 1 file changed, 1 insertion(+) diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index 401792de..c03f9c0b 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -173,6 +173,7 @@ impl DefmtLoggerInfo { // - use two Formatter in StdoutLogger instead of the log format // - add fn format_to_sink // - specify log format +#[derive(Debug)] pub struct Formatter { format: Vec, } From 133594c629961df2d1f794d580c918878e08762d Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Mon, 2 Oct 2023 19:30:53 +0200 Subject: [PATCH 06/15] Handle `defmt::println` separately --- decoder/src/log/mod.rs | 17 +++++++++++++---- 1 file changed, 13 insertions(+), 4 deletions(-) diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index c03f9c0b..f26bc6dc 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -16,7 +16,7 @@ use log::{Level, LevelFilter, Log, Metadata, Record}; use serde::{Deserialize, Serialize}; use self::{ - format::LogSegment, + format::{LogMetadata, LogSegment}, json_logger::JsonLogger, stdout_logger::{Printer, StdoutLogger}, }; @@ -208,9 +208,18 @@ impl Formatter { payload: Payload { level, timestamp }, }; - Printer::new_defmt(&record, &self.format) - .format_frame() - .unwrap() + match level { + Some(_) => Printer::new_defmt(&record, &self.format) + .format_frame() + .unwrap(), + None => { + // handle defmt::println separately + const RAW_FORMAT: &[LogSegment] = &[LogSegment::new(LogMetadata::Log)]; + Printer::new_defmt(&record, RAW_FORMAT) + .format_frame() + .unwrap() + } + } } } } From 6ba4b29cd852f658c5f323630e2d756cf7e41b68 Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Mon, 2 Oct 2023 19:38:53 +0200 Subject: [PATCH 07/15] Simplify --- decoder/src/log/mod.rs | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index f26bc6dc..0f15c7a1 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -164,7 +164,7 @@ impl DefmtLoggerInfo { } } -/// Format [DefmtRecord]s according to a `log_format`. +/// Format [`Frame`]s according to a `log_format`. /// /// The `log_format` makes it possible to customize the defmt output. /// @@ -209,17 +209,15 @@ impl Formatter { }; match level { - Some(_) => Printer::new_defmt(&record, &self.format) - .format_frame() - .unwrap(), + Some(_) => Printer::new_defmt(&record, &self.format), None => { // handle defmt::println separately const RAW_FORMAT: &[LogSegment] = &[LogSegment::new(LogMetadata::Log)]; Printer::new_defmt(&record, RAW_FORMAT) - .format_frame() - .unwrap() } } + .format_frame() + .unwrap() } } } From cb63a919c1b5308c84a801de5a3d978b07435ce0 Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Mon, 2 Oct 2023 19:43:47 +0200 Subject: [PATCH 08/15] Update `CHANGELOG.md` --- CHANGELOG.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index e08fde65..e95e8391 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,12 +7,14 @@ and this project adheres to [Semantic Versioning](http://semver.org/). ## [Unreleased] +- [#xxx]: `defmt-decoder`: Add `pub struct Formatter` to `defmt_decoder::log` - [#778]: `defmt-decoder`: Add support for nested log formatting - [#777]: `defmt-decoder`: Simplify StdoutLogger - [#775]: `defmt-decoder`: Ignore AArch64 mapping symbols - [#771]: `defmt-macros`: Ignore empty items in DEFMT_LOG - [#769]: `defmt-decoder`: Add support for color, style, width and alignment to format +[#xxx]: https://github.com/knurling-rs/defmt/pull/xxx [#778]: https://github.com/knurling-rs/defmt/pull/778 [#777]: https://github.com/knurling-rs/defmt/pull/777 [#775]: https://github.com/knurling-rs/defmt/pull/775 From da03a4b9e4a2e9c28f83f7075f5d06283eafa88b Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Mon, 2 Oct 2023 19:44:35 +0200 Subject: [PATCH 09/15] Update `CHANGELOG.md` --- CHANGELOG.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index e95e8391..a450bb0d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,14 +7,14 @@ and this project adheres to [Semantic Versioning](http://semver.org/). ## [Unreleased] -- [#xxx]: `defmt-decoder`: Add `pub struct Formatter` to `defmt_decoder::log` +- [#781]: `defmt-decoder`: Add `pub struct Formatter` to `defmt_decoder::log` - [#778]: `defmt-decoder`: Add support for nested log formatting - [#777]: `defmt-decoder`: Simplify StdoutLogger - [#775]: `defmt-decoder`: Ignore AArch64 mapping symbols - [#771]: `defmt-macros`: Ignore empty items in DEFMT_LOG - [#769]: `defmt-decoder`: Add support for color, style, width and alignment to format -[#xxx]: https://github.com/knurling-rs/defmt/pull/xxx +[#781]: https://github.com/knurling-rs/defmt/pull/781 [#778]: https://github.com/knurling-rs/defmt/pull/778 [#777]: https://github.com/knurling-rs/defmt/pull/777 [#775]: https://github.com/knurling-rs/defmt/pull/775 From 7f394b55e61d952a585064331b1a18510291ea02 Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Mon, 2 Oct 2023 20:08:12 +0200 Subject: [PATCH 10/15] Satisfy clippy --- decoder/src/log/mod.rs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index 0f15c7a1..a1e4d927 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -31,7 +31,7 @@ pub fn log_defmt( line: Option, module_path: Option<&str>, ) { - let (timestamp, level) = timestamp_and_level_from_frame(&frame); + let (timestamp, level) = timestamp_and_level_from_frame(frame); let target = format!( "{}{}", @@ -194,6 +194,7 @@ impl Formatter { ) -> String { let (timestamp, level) = timestamp_and_level_from_frame(&frame); + #[allow(clippy::match_single_binding)] match format_args!("{}", frame.display_message()) { args => { let log_record = &Record::builder() From 52b2e3b426aae850f5346677131b38e6a4c248d7 Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Tue, 3 Oct 2023 21:50:29 +0200 Subject: [PATCH 11/15] Simplify --- decoder/src/log/stdout_logger.rs | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index 13352b8d..21567cab 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -147,11 +147,7 @@ impl<'a> Printer<'a> { } pub fn new_defmt(record: &'a DefmtRecord<'a>, format: &'a [LogSegment]) -> Self { - Self { - record: Record::Defmt(record), - format, - min_timestamp_width: 0, - } + Self::new(Record::Defmt(record), format) } /// Pads the defmt timestamp to take up at least the given number of characters. From d524e439a6073016ae175d0ebc16853a39a9110f Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Tue, 3 Oct 2023 22:13:40 +0200 Subject: [PATCH 12/15] Writing to String cannot fail --- decoder/src/log/mod.rs | 1 - decoder/src/log/stdout_logger.rs | 8 ++++---- 2 files changed, 4 insertions(+), 5 deletions(-) diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index a1e4d927..291ae962 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -218,7 +218,6 @@ impl Formatter { } } .format_frame() - .unwrap() } } } diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index 21567cab..d3713d75 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -166,13 +166,13 @@ impl<'a> Printer<'a> { writeln!(sink) } - pub(super) fn format_frame(&self) -> Result { - let mut sink = String::new(); + pub(super) fn format_frame(&self) -> String { + let mut buf = String::new(); for segment in self.format { let s = self.build_segment(segment); - write!(sink, "{s}")?; + write!(buf, "{s}").expect("writing to String cannot fail"); } - Ok(sink) + buf } fn build_segment(&self, segment: &LogSegment) -> String { From 44a6d1bb18a32113b2b02bfb167cd5fd689b3f46 Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Tue, 3 Oct 2023 22:18:15 +0200 Subject: [PATCH 13/15] `DefmtRecord` does not have to be public --- decoder/src/log/mod.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index 291ae962..aefa7c77 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -57,7 +57,7 @@ pub fn is_defmt_frame(metadata: &Metadata) -> bool { } /// A `log` record representing a defmt log frame. -pub struct DefmtRecord<'a> { +struct DefmtRecord<'a> { log_record: &'a Record<'a>, payload: Payload, } From 9fb5392afa06425b4f4747f89e81e7220403aed5 Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Tue, 3 Oct 2023 22:18:28 +0200 Subject: [PATCH 14/15] Document match-binding hack --- decoder/src/log/mod.rs | 1 + 1 file changed, 1 insertion(+) diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index aefa7c77..c6b6676b 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -194,6 +194,7 @@ impl Formatter { ) -> String { let (timestamp, level) = timestamp_and_level_from_frame(&frame); + // HACK: use match instead of let, because otherwise compilation fails #[allow(clippy::match_single_binding)] match format_args!("{}", frame.display_message()) { args => { From d48b7396ad747bc1ca9ea4f638e1ab4dc85af1c6 Mon Sep 17 00:00:00 2001 From: Johann Hemmann Date: Wed, 4 Oct 2023 15:45:34 +0200 Subject: [PATCH 15/15] Document Formatter-Printer-discussion --- decoder/src/log/mod.rs | 1 + 1 file changed, 1 insertion(+) diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index c6b6676b..de603cba 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -173,6 +173,7 @@ impl DefmtLoggerInfo { // - use two Formatter in StdoutLogger instead of the log format // - add fn format_to_sink // - specify log format +// - clarify relationship between Formatter and Printer (https://github.com/knurling-rs/defmt/pull/781#discussion_r1343000073) #[derive(Debug)] pub struct Formatter { format: Vec,