From 9c618796a45faa90fca1655c56713c4c3065c3d2 Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Sat, 15 Jul 2023 15:32:48 +0200 Subject: [PATCH 01/20] Add support for customizable logger formatting --- decoder/Cargo.toml | 1 + decoder/src/log/format.rs | 110 +++++++++++++ decoder/src/log/json_logger.rs | 6 +- decoder/src/log/mod.rs | 30 +++- decoder/src/log/stdout_logger.rs | 274 ++++++++++++++++--------------- 5 files changed, 279 insertions(+), 142 deletions(-) create mode 100644 decoder/src/log/format.rs diff --git a/decoder/Cargo.toml b/decoder/Cargo.toml index 793bf972..a9bb6539 100644 --- a/decoder/Cargo.toml +++ b/decoder/Cargo.toml @@ -14,6 +14,7 @@ byteorder = "1" colored = "2" defmt-parser = { version = "=0.3.3", path = "../parser", features = ["unstable"] } ryu = "1" +nom = "7" # display time = { version = "0.3", default-features = false, features = [ diff --git a/decoder/src/log/format.rs b/decoder/src/log/format.rs new file mode 100644 index 00000000..79c4ac2c --- /dev/null +++ b/decoder/src/log/format.rs @@ -0,0 +1,110 @@ +use nom::IResult; +use nom::bytes::complete::{take, take_till1}; +use nom::character::complete::char; +use nom::combinator::{map_res, map}; +use nom::error::{FromExternalError, ParseError}; +use nom::multi::many0; +use nom::sequence::delimited; +use nom::branch::alt; +use nom::Parser; + +#[derive(Debug, PartialEq, Clone)] +#[non_exhaustive] +pub enum LogSegment { + String(String), + Timestamp, + FileName, + FilePath, + ModulePath, + LineNumber, + LogLevel, + Log, +} + +#[derive(Debug, PartialEq)] +pub struct InvalidArgument; + +fn parse_argument<'a, E>(input: &'a str) -> IResult<&'a str, LogSegment, E> +where E: ParseError<&'a str> + FromExternalError<&'a str, InvalidArgument>, { + let parse_enclosed = delimited(char('{'), take(1u32), char('}')); + let mut parse_type = map_res(parse_enclosed, move |s| { + match s { + "t" => Ok(LogSegment::Timestamp), + "f" => Ok(LogSegment::FileName), + "F" => Ok(LogSegment::FilePath), + "m" => Ok(LogSegment::ModulePath), + "l" => Ok(LogSegment::LineNumber), + "L" => Ok(LogSegment::LogLevel), + "s" => Ok(LogSegment::Log), + _ => Err(InvalidArgument), + } + }); + + parse_type.parse(input) +} + +fn parse_string_segment<'a, E>(input: &'a str) -> IResult<&'a str, LogSegment, E> +where E: ParseError<&'a str>, { + map(take_till1(|c| c == '{'),|s: &str| LogSegment::String(s.to_string())).parse(input) +} + +pub fn parse<'a>(input: &'a str) -> Result, String> { + let mut parse_all = many0(alt((parse_argument::<()>, parse_string_segment))); + + parse_all(input).map(|(_, output)| output).map_err(|e| e.to_string()) +} + + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn test_parse_log_template() { + let log_template = "{t} [{L}] {s}\n└─ {m} @ {F}:{l}"; + + let expected_output = vec![ + LogSegment::Timestamp, + LogSegment::String(" [".to_string()), + LogSegment::LogLevel, + LogSegment::String("] ".to_string()), + LogSegment::Log, + LogSegment::String("\n└─ ".to_string()), + LogSegment::ModulePath, + LogSegment::String(" @ ".to_string()), + LogSegment::FilePath, + LogSegment::String(":".to_string()), + LogSegment::LineNumber, + ]; + + let result = parse(log_template); + assert_eq!(result, Ok(expected_output)); + } + + #[test] + fn test_parse_string_segment() { + let result = parse_string_segment::<()>("Log: {t}"); + let (input, output) = result.unwrap(); + assert_eq!(input, "{t}"); + assert_eq!(output, LogSegment::String("Log: ".to_string())); + } + + #[test] + fn test_parse_empty_string_segment() { + let result = parse_string_segment::<()>(""); + assert!(result.is_err()); + } + + #[test] + fn test_parse_timestamp_argument() { + let result = parse_argument::<()>("{t}"); + assert_eq!(result, Ok(("", LogSegment::Timestamp))); + } + + #[test] + fn test_parse_invalid_argument() { + let result = parse_argument::<()>("{foo}"); + let result = dbg!(result); + assert_eq!(result, Result::Err(nom::Err::Error(()))); + } +} diff --git a/decoder/src/log/json_logger.rs b/decoder/src/log/json_logger.rs index 806c780d..f646f0d0 100644 --- a/decoder/src/log/json_logger.rs +++ b/decoder/src/log/json_logger.rs @@ -4,7 +4,7 @@ use time::OffsetDateTime; use std::io::{self, Write}; -use super::{DefmtRecord, StdoutLogger}; +use super::{stdout_logger::StdoutLogger, DefmtRecord}; pub(crate) struct JsonLogger { should_log: Box bool + Sync + Send>, @@ -41,10 +41,10 @@ impl Log for JsonLogger { } impl JsonLogger { - pub fn new(should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static) -> Box { + pub fn new<'a>(log_format: Option<&'a str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static) -> Box { Box::new(Self { should_log: Box::new(should_log), - host_logger: StdoutLogger::new_unboxed(true, |_| true), + host_logger: StdoutLogger::new_unboxed(log_format, |_| true), }) } diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index 1d01d571..c036eb9f 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -8,6 +8,7 @@ mod json_logger; mod stdout_logger; +mod format; use log::{Level, LevelFilter, Metadata, Record}; use serde::{Deserialize, Serialize}; @@ -115,23 +116,36 @@ impl<'a> DefmtRecord<'a> { /// Initializes a `log` sink that handles defmt frames. /// /// Defmt frames will be printed to stdout, other logs to stderr. -/// +/// /// The caller has to provide a `should_log` closure that determines whether a log record should be /// printed. +/// +/// An optional `log_format` string can be provided to format the way +/// logs are printed. A format string could look as follows: +/// "{t} [{L}] Location<{f}:{l}> {s}" /// -/// If `always_include_location` is `true`, a second line containing location information will be -/// printed for *all* records, not just for defmt frames (defmt frames always get location info -/// included if it is available, regardless of this setting). -pub fn init_logger( - always_include_location: bool, +/// The arguments between curly braces are placeholders for log metadata. +/// The following arguments are supported: +/// - {t} : log timestamp +/// - {f} : file name (e.g. "main.rs") +/// - {F} : file path (e.g. "home/app/main.rs") +/// - {m} : module path (e.g. "foo/bar/some_function") +/// - {l} : line number +/// - {L} : log level (e.g. "INFO", "DEBUG", etc) +/// - {s} : the actual log +/// +/// For example, with the log format shown above, a log would look like this: +/// "23124 [INFO] Location Hello, world!" +pub fn init_logger<'a>( + log_format: Option<&'a str>, json: bool, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) { log::set_boxed_logger(match json { - false => StdoutLogger::new(always_include_location, should_log), + false => StdoutLogger::new(log_format, should_log), true => { JsonLogger::print_schema_version(); - JsonLogger::new(should_log) + JsonLogger::new(log_format, should_log) } }) .unwrap(); diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index ff125de1..5a29abc4 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -1,20 +1,26 @@ use colored::{Color, Colorize}; use dissimilar::Chunk; -use log::{Level, Log, Metadata, Record}; +use log::{Level, Log, Metadata, Record as LogRecord}; use std::{ fmt::Write as _, - io::{self, StderrLock, StdoutLock, Write}, - sync::atomic::{AtomicUsize, Ordering}, + io::{self, StderrLock, StdoutLock}, + sync::atomic::{AtomicUsize, Ordering}, path::Path, }; -use super::DefmtRecord; +use super::{DefmtRecord, format::LogSegment}; +use super::format; + +enum Record<'a> { + Defmt(&'a DefmtRecord<'a>), + Host(&'a LogRecord<'a>), +} pub(crate) struct StdoutLogger { - always_include_location: bool, + format: Vec, should_log: Box bool + Sync + Send>, - /// Number of characters used by the timestamp. This may increase over time and is used to align - /// messages. + /// Number of characters used by the timestamp. + /// This may increase over time and is used to align messages. timing_align: AtomicUsize, } @@ -23,7 +29,7 @@ impl Log for StdoutLogger { (self.should_log)(metadata) } - fn log(&self, record: &Record) { + fn log(&self, record: &LogRecord) { if !self.enabled(record.metadata()) { return; } @@ -32,11 +38,7 @@ impl Log for StdoutLogger { Some(record) => { // defmt goes to stdout, since it's the primary output produced by this tool. let sink = io::stdout().lock(); - - match record.level() { - Some(level) => self.print_defmt_record(record, level, sink), - None => Self::print_println_record(record, sink), - }; + self.print_defmt_record(record, sink); } None => { // non-defmt logs go to stderr @@ -50,152 +52,181 @@ impl Log for StdoutLogger { } impl StdoutLogger { - pub fn new( - always_include_location: bool, + pub fn new<'a>( + log_format: Option<&'a str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) -> Box { - Box::new(Self::new_unboxed(always_include_location, should_log)) + Box::new(Self::new_unboxed(log_format, should_log)) } - pub fn new_unboxed( - always_include_location: bool, + pub fn new_unboxed<'a>( + log_format: Option<&'a str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) -> Self { + let format = log_format.unwrap_or("{t} [{L}] {s}\n└─ {m} @ {F}:{l}"); + + // TODO: Handle errors + let format = format::parse(format).unwrap(); Self { - always_include_location, + format, should_log: Box::new(should_log), timing_align: AtomicUsize::new(0), } } - fn print_defmt_record(&self, record: DefmtRecord, level: Level, mut sink: StdoutLock) { + fn print_defmt_record(&self, record: DefmtRecord, mut sink: StdoutLock) { let len = record.timestamp().len(); self.timing_align.fetch_max(len, Ordering::Relaxed); let min_timestamp_width = self.timing_align.load(Ordering::Relaxed); - Printer::new(&record, level) - .include_location(true) // always include location for defmt output + Printer::new(Record::Defmt(&record), &self.format) .min_timestamp_width(min_timestamp_width) - .print_colored(&mut sink) + .print_frame(&mut sink) .ok(); } - pub(super) fn print_host_record(&self, record: &Record, mut sink: StderrLock) { + pub(super) fn print_host_record(&self, record: &LogRecord, mut sink: StderrLock) { let min_timestamp_width = self.timing_align.load(Ordering::Relaxed); - - writeln!( - sink, - "{timestamp:>0$} {level:5} {args}", - min_timestamp_width, - timestamp = "(HOST)", - level = record - .level() - .to_string() - .color(color_for_log_level(record.level())), - args = record.args() - ) - .ok(); - - if self.always_include_location { - print_location( - &mut sink, - record.file(), - record.line(), - record.module_path(), - ) - .ok(); - } - } - - fn print_println_record(record: DefmtRecord, mut sink: StdoutLock) { - let timestamp = match record.timestamp().is_empty() { - true => record.timestamp().to_string(), - false => format!("{} ", record.timestamp()), - }; - - writeln!(&mut sink, "{timestamp}{}", record.args()).ok(); - print_location( - &mut sink, - record.file(), - record.line(), - record.module_path(), - ) + Printer::new(Record::Host(&record), &self.format) + .min_timestamp_width(min_timestamp_width) + .print_frame(&mut sink) .ok(); } } /// Printer for `DefmtRecord`s. -pub struct Printer<'a> { - record: &'a DefmtRecord<'a>, - include_location: bool, - level: Level, +struct Printer<'a> { + record: Record<'a>, + format: &'a [LogSegment], min_timestamp_width: usize, } impl<'a> Printer<'a> { - pub fn new(record: &'a DefmtRecord, level: Level) -> Self { + pub fn new(record: Record<'a>, format: &'a [LogSegment]) -> Self { Self { record, - include_location: false, - level, + format, min_timestamp_width: 0, } } - /// Configure whether to include location info (file, line) in the output. - /// - /// If `true`, an additional line will be included in the output that contains file and line - /// information of the logging statement. - /// By default, this is `false`. - pub fn include_location(&mut self, include_location: bool) -> &mut Self { - self.include_location = include_location; - self - } - /// Pads the defmt timestamp to take up at least the given number of characters. pub fn min_timestamp_width(&mut self, min_timestamp_width: usize) -> &mut Self { self.min_timestamp_width = min_timestamp_width; self } - /// Prints the colored log frame to `sink`. - /// - /// The format is as follows (this is not part of the stable API and may change): - /// - /// ```text - /// - /// └─ @ : - /// ``` - pub fn print_colored(&self, sink: &mut W) -> io::Result<()> { - writeln!( + /// Prints the formatted log frame to `sink`. + pub fn print_frame(&self, sink: &mut W) -> io::Result<()> { + for segment in self.format { + match segment { + LogSegment::String(s) => self.print_string(sink, &s), + LogSegment::Timestamp => self.print_timestamp(sink), + LogSegment::FileName => self.print_file_name(sink), + LogSegment::FilePath => self.print_file_path(sink), + LogSegment::ModulePath => self.print_module_path(sink), + LogSegment::LineNumber => self.print_line_number(sink), + LogSegment::LogLevel => self.print_log_level(sink), + LogSegment::Log => self.print_log(sink), + }?; + } + writeln!(sink)?; + Ok(()) + } + + fn print_string(&self, sink: &mut W, s: &str) -> io::Result<()> { + write!(sink, "{s}") + } + + fn print_timestamp(&self, sink: &mut W) -> io::Result<()> { + let timestamp = match self.record { + Record::Defmt(record) => record.timestamp().to_string(), + Record::Host(_) => String::from("(HOST)"), + }; + + write!( sink, - "{timestamp:>0$}{spacing}{level:5} {args}", + "{timestamp:>0$}", self.min_timestamp_width, - timestamp = self.record.timestamp(), - spacing = if self.record.timestamp().is_empty() { - "" + ) + } + + fn print_log_level(&self, sink: &mut W) -> io::Result<()> { + let level = match self.record { + Record::Defmt(record) => record.level(), + Record::Host(record) => Some(record.level()), + }; + + let level = if let Some(level) = level { + // TODO: Should the color be customizable via the format too? + level.to_string().color(color_for_log_level(level)).to_string() + } else { + String::from("level") + }; + + write!(sink, "{level:5}") + } + + fn print_file_path(&self, sink: &mut W) -> io::Result<()> { + let file_path = match self.record { + Record::Defmt(record) => record.file(), + Record::Host(record) => record.file(), + }.unwrap_or(""); + + write!(sink, "{file_path}") + } + + fn print_file_name(&self, sink: &mut W) -> io::Result<()> { + let file = match self.record { + Record::Defmt(record) => record.file(), + Record::Host(record) => record.file(), + }; + + let file_name = if let Some(file) = file { + let file_name = Path::new(file).file_name(); + if let Some(file_name) = file_name { + file_name.to_str().unwrap_or("") } else { - " " - }, - level = self - .level - .to_string() - .color(color_for_log_level(self.level)), - args = color_diff(self.record.args().to_string()), - )?; - - if self.include_location { - let log_record = self.record.log_record; - print_location( - sink, - log_record.file(), - log_record.line(), - log_record.module_path(), - )?; - } + "" + } + } else { + "" + }; - Ok(()) + write!(sink, "{file_name}") + } + + fn print_module_path(&self, sink: &mut W) -> io::Result<()> { + let module_path = match self.record { + Record::Defmt(record) => record.module_path(), + Record::Host(record) => record.module_path(), + }.unwrap_or(""); + + write!(sink, "{module_path}") } + + fn print_line_number(&self, sink: &mut W) -> io::Result<()> { + let line_number = match self.record { + Record::Defmt(record) => record.line(), + Record::Host(record) => record.line(), + }.unwrap_or(0); + + write!(sink, "{line_number}") + } + + fn print_log(&self, sink: &mut W) -> io::Result<()> { + let args = match self.record { + Record::Defmt(record) => record.args(), + Record::Host(record) => record.args(), + }; + + write!( + sink, + "{log}", + log = color_diff(args.to_string()), + ) + } + } // color the output of `defmt::assert_eq` @@ -276,22 +307,3 @@ fn color_for_log_level(level: Level) -> Color { Level::Trace => Color::BrightBlack, } } - -fn print_location( - sink: &mut W, - file: Option<&str>, - line: Option, - module_path: Option<&str>, -) -> io::Result<()> { - if let Some(file) = file { - // NOTE will always be `Some` if `file` is `Some` - let mod_path = module_path.unwrap(); - let mut loc = file.to_string(); - if let Some(line) = line { - let _ = write!(loc, ":{line}"); - } - writeln!(sink, "{}", format!("└─ {mod_path} @ {loc}").dimmed())?; - } - - Ok(()) -} From d445bedd4df430f6dddf00318680f2ead32235c5 Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Sat, 15 Jul 2023 15:52:17 +0200 Subject: [PATCH 02/20] print: add support for log_format for decoder --- print/src/main.rs | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/print/src/main.rs b/print/src/main.rs index 65559abb..d6ea3d13 100644 --- a/print/src/main.rs +++ b/print/src/main.rs @@ -19,6 +19,9 @@ struct Opts { #[arg(long)] json: bool, + #[arg(long)] + log_format: Option, + #[arg(long)] show_skipped_frames: bool, @@ -80,6 +83,7 @@ fn main() -> anyhow::Result<()> { let Opts { elf, json, + log_format, show_skipped_frames, verbose, version, @@ -90,7 +94,9 @@ fn main() -> anyhow::Result<()> { return print_version(); } - defmt_decoder::log::init_logger(verbose, json, move |metadata| match verbose { + let log_format = log_format.as_ref().map(|s| s.as_str()); + + defmt_decoder::log::init_logger(log_format, json, move |metadata| match verbose { false => defmt_decoder::log::is_defmt_frame(metadata), // We display *all* defmt frames, but nothing else. true => true, // We display *all* frames. }); From 02716c371c5a51e7f7b0a4515ffa7210f723d9d9 Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Sat, 15 Jul 2023 15:58:23 +0200 Subject: [PATCH 03/20] Fix CI (fmt, clippy, changelog) --- CHANGELOG.md | 3 +++ decoder/src/log/format.rs | 2 +- decoder/src/log/json_logger.rs | 2 +- decoder/src/log/mod.rs | 4 ++-- decoder/src/log/stdout_logger.rs | 12 ++++++------ print/src/main.rs | 4 +--- 6 files changed, 14 insertions(+), 13 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index d01a2b39..fd683558 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,9 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/) and this project adheres to [Semantic Versioning](http://semver.org/). ## [Unreleased] +- [#765]: `defmt-decoder`: Add support for customizable logger formatting + +[#765]: https://github.com/knurling-rs/defmt/pull/765 - [#766] `decoder::log`: Rename `PrettyLogger` to `StdoutLogger` diff --git a/decoder/src/log/format.rs b/decoder/src/log/format.rs index 79c4ac2c..6bdcd350 100644 --- a/decoder/src/log/format.rs +++ b/decoder/src/log/format.rs @@ -48,7 +48,7 @@ where E: ParseError<&'a str>, { map(take_till1(|c| c == '{'),|s: &str| LogSegment::String(s.to_string())).parse(input) } -pub fn parse<'a>(input: &'a str) -> Result, String> { +pub fn parse(input: &str) -> Result, String> { let mut parse_all = many0(alt((parse_argument::<()>, parse_string_segment))); parse_all(input).map(|(_, output)| output).map_err(|e| e.to_string()) diff --git a/decoder/src/log/json_logger.rs b/decoder/src/log/json_logger.rs index f646f0d0..17df7a0e 100644 --- a/decoder/src/log/json_logger.rs +++ b/decoder/src/log/json_logger.rs @@ -41,7 +41,7 @@ impl Log for JsonLogger { } impl JsonLogger { - pub fn new<'a>(log_format: Option<&'a str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static) -> Box { + pub fn new(log_format: Option<&str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static) -> Box { Box::new(Self { should_log: Box::new(should_log), host_logger: StdoutLogger::new_unboxed(log_format, |_| true), diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index c036eb9f..f545dc4a 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -136,8 +136,8 @@ impl<'a> DefmtRecord<'a> { /// /// For example, with the log format shown above, a log would look like this: /// "23124 [INFO] Location Hello, world!" -pub fn init_logger<'a>( - log_format: Option<&'a str>, +pub fn init_logger( + log_format: Option<&str>, json: bool, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) { diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index 5a29abc4..117254eb 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -52,15 +52,15 @@ impl Log for StdoutLogger { } impl StdoutLogger { - pub fn new<'a>( - log_format: Option<&'a str>, + pub fn new( + log_format: Option<&str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) -> Box { Box::new(Self::new_unboxed(log_format, should_log)) } - pub fn new_unboxed<'a>( - log_format: Option<&'a str>, + pub fn new_unboxed( + log_format: Option<&str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) -> Self { let format = log_format.unwrap_or("{t} [{L}] {s}\n└─ {m} @ {F}:{l}"); @@ -87,7 +87,7 @@ impl StdoutLogger { pub(super) fn print_host_record(&self, record: &LogRecord, mut sink: StderrLock) { let min_timestamp_width = self.timing_align.load(Ordering::Relaxed); - Printer::new(Record::Host(&record), &self.format) + Printer::new(Record::Host(record), &self.format) .min_timestamp_width(min_timestamp_width) .print_frame(&mut sink) .ok(); @@ -120,7 +120,7 @@ impl<'a> Printer<'a> { pub fn print_frame(&self, sink: &mut W) -> io::Result<()> { for segment in self.format { match segment { - LogSegment::String(s) => self.print_string(sink, &s), + LogSegment::String(s) => self.print_string(sink, s), LogSegment::Timestamp => self.print_timestamp(sink), LogSegment::FileName => self.print_file_name(sink), LogSegment::FilePath => self.print_file_path(sink), diff --git a/print/src/main.rs b/print/src/main.rs index d6ea3d13..922f26da 100644 --- a/print/src/main.rs +++ b/print/src/main.rs @@ -94,9 +94,7 @@ fn main() -> anyhow::Result<()> { return print_version(); } - let log_format = log_format.as_ref().map(|s| s.as_str()); - - defmt_decoder::log::init_logger(log_format, json, move |metadata| match verbose { + defmt_decoder::log::init_logger(log_format.as_deref(), json, move |metadata| match verbose { false => defmt_decoder::log::is_defmt_frame(metadata), // We display *all* defmt frames, but nothing else. true => true, // We display *all* frames. }); From 7d65adc93e775bb305621f8f95e5c839592616cb Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Sat, 15 Jul 2023 16:02:43 +0200 Subject: [PATCH 04/20] cargo fmt --- decoder/src/log/format.rs | 44 ++++++++++++++++++-------------- decoder/src/log/json_logger.rs | 5 +++- decoder/src/log/mod.rs | 8 +++--- decoder/src/log/stdout_logger.rs | 44 +++++++++++++++----------------- 4 files changed, 54 insertions(+), 47 deletions(-) diff --git a/decoder/src/log/format.rs b/decoder/src/log/format.rs index 6bdcd350..4e938f61 100644 --- a/decoder/src/log/format.rs +++ b/decoder/src/log/format.rs @@ -1,11 +1,11 @@ -use nom::IResult; +use nom::branch::alt; use nom::bytes::complete::{take, take_till1}; use nom::character::complete::char; -use nom::combinator::{map_res, map}; +use nom::combinator::{map, map_res}; use nom::error::{FromExternalError, ParseError}; use nom::multi::many0; use nom::sequence::delimited; -use nom::branch::alt; +use nom::IResult; use nom::Parser; #[derive(Debug, PartialEq, Clone)] @@ -25,36 +25,42 @@ pub enum LogSegment { pub struct InvalidArgument; fn parse_argument<'a, E>(input: &'a str) -> IResult<&'a str, LogSegment, E> -where E: ParseError<&'a str> + FromExternalError<&'a str, InvalidArgument>, { +where + E: ParseError<&'a str> + FromExternalError<&'a str, InvalidArgument>, +{ let parse_enclosed = delimited(char('{'), take(1u32), char('}')); - let mut parse_type = map_res(parse_enclosed, move |s| { - match s { - "t" => Ok(LogSegment::Timestamp), - "f" => Ok(LogSegment::FileName), - "F" => Ok(LogSegment::FilePath), - "m" => Ok(LogSegment::ModulePath), - "l" => Ok(LogSegment::LineNumber), - "L" => Ok(LogSegment::LogLevel), - "s" => Ok(LogSegment::Log), - _ => Err(InvalidArgument), - } + let mut parse_type = map_res(parse_enclosed, move |s| match s { + "t" => Ok(LogSegment::Timestamp), + "f" => Ok(LogSegment::FileName), + "F" => Ok(LogSegment::FilePath), + "m" => Ok(LogSegment::ModulePath), + "l" => Ok(LogSegment::LineNumber), + "L" => Ok(LogSegment::LogLevel), + "s" => Ok(LogSegment::Log), + _ => Err(InvalidArgument), }); parse_type.parse(input) } fn parse_string_segment<'a, E>(input: &'a str) -> IResult<&'a str, LogSegment, E> -where E: ParseError<&'a str>, { - map(take_till1(|c| c == '{'),|s: &str| LogSegment::String(s.to_string())).parse(input) +where + E: ParseError<&'a str>, +{ + map(take_till1(|c| c == '{'), |s: &str| { + LogSegment::String(s.to_string()) + }) + .parse(input) } pub fn parse(input: &str) -> Result, String> { let mut parse_all = many0(alt((parse_argument::<()>, parse_string_segment))); - parse_all(input).map(|(_, output)| output).map_err(|e| e.to_string()) + parse_all(input) + .map(|(_, output)| output) + .map_err(|e| e.to_string()) } - #[cfg(test)] mod tests { use super::*; diff --git a/decoder/src/log/json_logger.rs b/decoder/src/log/json_logger.rs index 17df7a0e..17c25f8d 100644 --- a/decoder/src/log/json_logger.rs +++ b/decoder/src/log/json_logger.rs @@ -41,7 +41,10 @@ impl Log for JsonLogger { } impl JsonLogger { - pub fn new(log_format: Option<&str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static) -> Box { + pub fn new( + log_format: Option<&str>, + should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, + ) -> Box { Box::new(Self { should_log: Box::new(should_log), host_logger: StdoutLogger::new_unboxed(log_format, |_| true), diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index f545dc4a..320200f3 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -6,9 +6,9 @@ //! [`log`]: https://crates.io/crates/log //! [`defmt`]: https://crates.io/crates/defmt +mod format; mod json_logger; mod stdout_logger; -mod format; use log::{Level, LevelFilter, Metadata, Record}; use serde::{Deserialize, Serialize}; @@ -116,10 +116,10 @@ impl<'a> DefmtRecord<'a> { /// Initializes a `log` sink that handles defmt frames. /// /// Defmt frames will be printed to stdout, other logs to stderr. -/// +/// /// The caller has to provide a `should_log` closure that determines whether a log record should be /// printed. -/// +/// /// An optional `log_format` string can be provided to format the way /// logs are printed. A format string could look as follows: /// "{t} [{L}] Location<{f}:{l}> {s}" @@ -133,7 +133,7 @@ impl<'a> DefmtRecord<'a> { /// - {l} : line number /// - {L} : log level (e.g. "INFO", "DEBUG", etc) /// - {s} : the actual log -/// +/// /// For example, with the log format shown above, a log would look like this: /// "23124 [INFO] Location Hello, world!" pub fn init_logger( diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index 117254eb..e0b9ecdf 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -5,11 +5,12 @@ use log::{Level, Log, Metadata, Record as LogRecord}; use std::{ fmt::Write as _, io::{self, StderrLock, StdoutLock}, - sync::atomic::{AtomicUsize, Ordering}, path::Path, + path::Path, + sync::atomic::{AtomicUsize, Ordering}, }; -use super::{DefmtRecord, format::LogSegment}; use super::format; +use super::{format::LogSegment, DefmtRecord}; enum Record<'a> { Defmt(&'a DefmtRecord<'a>), @@ -88,9 +89,9 @@ impl StdoutLogger { pub(super) fn print_host_record(&self, record: &LogRecord, mut sink: StderrLock) { let min_timestamp_width = self.timing_align.load(Ordering::Relaxed); Printer::new(Record::Host(record), &self.format) - .min_timestamp_width(min_timestamp_width) - .print_frame(&mut sink) - .ok(); + .min_timestamp_width(min_timestamp_width) + .print_frame(&mut sink) + .ok(); } } @@ -143,12 +144,8 @@ impl<'a> Printer<'a> { Record::Defmt(record) => record.timestamp().to_string(), Record::Host(_) => String::from("(HOST)"), }; - - write!( - sink, - "{timestamp:>0$}", - self.min_timestamp_width, - ) + + write!(sink, "{timestamp:>0$}", self.min_timestamp_width,) } fn print_log_level(&self, sink: &mut W) -> io::Result<()> { @@ -156,10 +153,13 @@ impl<'a> Printer<'a> { Record::Defmt(record) => record.level(), Record::Host(record) => Some(record.level()), }; - + let level = if let Some(level) = level { // TODO: Should the color be customizable via the format too? - level.to_string().color(color_for_log_level(level)).to_string() + level + .to_string() + .color(color_for_log_level(level)) + .to_string() } else { String::from("level") }; @@ -171,7 +171,8 @@ impl<'a> Printer<'a> { let file_path = match self.record { Record::Defmt(record) => record.file(), Record::Host(record) => record.file(), - }.unwrap_or(""); + } + .unwrap_or(""); write!(sink, "{file_path}") } @@ -181,7 +182,7 @@ impl<'a> Printer<'a> { Record::Defmt(record) => record.file(), Record::Host(record) => record.file(), }; - + let file_name = if let Some(file) = file { let file_name = Path::new(file).file_name(); if let Some(file_name) = file_name { @@ -200,7 +201,8 @@ impl<'a> Printer<'a> { let module_path = match self.record { Record::Defmt(record) => record.module_path(), Record::Host(record) => record.module_path(), - }.unwrap_or(""); + } + .unwrap_or(""); write!(sink, "{module_path}") } @@ -209,7 +211,8 @@ impl<'a> Printer<'a> { let line_number = match self.record { Record::Defmt(record) => record.line(), Record::Host(record) => record.line(), - }.unwrap_or(0); + } + .unwrap_or(0); write!(sink, "{line_number}") } @@ -220,13 +223,8 @@ impl<'a> Printer<'a> { Record::Host(record) => record.args(), }; - write!( - sink, - "{log}", - log = color_diff(args.to_string()), - ) + write!(sink, "{log}", log = color_diff(args.to_string()),) } - } // color the output of `defmt::assert_eq` From 3549fad2abf18e387d206fc0d69025ca0af1c867 Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Sat, 15 Jul 2023 16:14:15 +0200 Subject: [PATCH 05/20] Remove unnecessary `Ok(())` --- decoder/src/log/stdout_logger.rs | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index e0b9ecdf..8e7cf240 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -131,8 +131,7 @@ impl<'a> Printer<'a> { LogSegment::Log => self.print_log(sink), }?; } - writeln!(sink)?; - Ok(()) + writeln!(sink) } fn print_string(&self, sink: &mut W, s: &str) -> io::Result<()> { From 11fdfc4b06490e3ed73e8182a69ad0b86721fcd1 Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Sun, 16 Jul 2023 02:11:44 +0200 Subject: [PATCH 06/20] Handle log format parsing error --- decoder/src/log/stdout_logger.rs | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index 8e7cf240..a743b599 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -64,10 +64,14 @@ impl StdoutLogger { log_format: Option<&str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) -> Self { - let format = log_format.unwrap_or("{t} [{L}] {s}\n└─ {m} @ {F}:{l}"); + const DEFAULT_LOG_FORMAT: &str = "{t} {L} {s}\n└─ {m} @ {F}:{l}"; + + let format = log_format.unwrap_or(DEFAULT_LOG_FORMAT); + let format = format::parse(format).unwrap_or_else(|_| { + // Use the default format if the user-provided format is invalid + format::parse(DEFAULT_LOG_FORMAT).unwrap() + }); - // TODO: Handle errors - let format = format::parse(format).unwrap(); Self { format, should_log: Box::new(should_log), @@ -160,7 +164,7 @@ impl<'a> Printer<'a> { .color(color_for_log_level(level)) .to_string() } else { - String::from("level") + String::from("") }; write!(sink, "{level:5}") From 802f1b83229ad6db17e4051347a7b85f409f2615 Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Sun, 16 Jul 2023 02:13:01 +0200 Subject: [PATCH 07/20] cargo fmt --- decoder/src/log/stdout_logger.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index a743b599..38cfe24d 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -65,7 +65,7 @@ impl StdoutLogger { should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) -> Self { const DEFAULT_LOG_FORMAT: &str = "{t} {L} {s}\n└─ {m} @ {F}:{l}"; - + let format = log_format.unwrap_or(DEFAULT_LOG_FORMAT); let format = format::parse(format).unwrap_or_else(|_| { // Use the default format if the user-provided format is invalid From ea295e8a61a0408e7f435342cb97c75401934b1f Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Sun, 16 Jul 2023 12:20:05 +0200 Subject: [PATCH 08/20] Remove dbg! in test --- decoder/src/log/format.rs | 1 - 1 file changed, 1 deletion(-) diff --git a/decoder/src/log/format.rs b/decoder/src/log/format.rs index 4e938f61..cdabad13 100644 --- a/decoder/src/log/format.rs +++ b/decoder/src/log/format.rs @@ -110,7 +110,6 @@ mod tests { #[test] fn test_parse_invalid_argument() { let result = parse_argument::<()>("{foo}"); - let result = dbg!(result); assert_eq!(result, Result::Err(nom::Err::Error(()))); } } From d67d1e54bd466c6436af4d410aa1368e1b666d9e Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Sun, 16 Jul 2023 15:26:38 +0200 Subject: [PATCH 09/20] Fix wrong comment about module_path --- 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 320200f3..84993670 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -129,7 +129,7 @@ impl<'a> DefmtRecord<'a> { /// - {t} : log timestamp /// - {f} : file name (e.g. "main.rs") /// - {F} : file path (e.g. "home/app/main.rs") -/// - {m} : module path (e.g. "foo/bar/some_function") +/// - {m} : module path (e.g. "foo::bar::some_function") /// - {l} : line number /// - {L} : log level (e.g. "INFO", "DEBUG", etc) /// - {s} : the actual log From 938d34c6ebdf331d725245e58e203f6eb571c0ae Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Mon, 17 Jul 2023 20:34:28 +0200 Subject: [PATCH 10/20] Apply requested changes --- decoder/src/log/format.rs | 61 ++++++++++++++------------------ decoder/src/log/stdout_logger.rs | 6 ++-- 2 files changed, 30 insertions(+), 37 deletions(-) diff --git a/decoder/src/log/format.rs b/decoder/src/log/format.rs index cdabad13..428799fa 100644 --- a/decoder/src/log/format.rs +++ b/decoder/src/log/format.rs @@ -1,60 +1,51 @@ -use nom::branch::alt; -use nom::bytes::complete::{take, take_till1}; -use nom::character::complete::char; -use nom::combinator::{map, map_res}; -use nom::error::{FromExternalError, ParseError}; -use nom::multi::many0; -use nom::sequence::delimited; -use nom::IResult; -use nom::Parser; +use nom::{ + branch::alt, + bytes::complete::{take, take_till1}, + character::complete::char, + combinator::{map, map_res}, + multi::many0, + sequence::delimited, + IResult, Parser, +}; #[derive(Debug, PartialEq, Clone)] #[non_exhaustive] -pub enum LogSegment { - String(String), - Timestamp, +pub(super) enum LogSegment { FileName, FilePath, - ModulePath, LineNumber, - LogLevel, Log, + LogLevel, + ModulePath, + String(String), + Timestamp, } -#[derive(Debug, PartialEq)] -pub struct InvalidArgument; - -fn parse_argument<'a, E>(input: &'a str) -> IResult<&'a str, LogSegment, E> -where - E: ParseError<&'a str> + FromExternalError<&'a str, InvalidArgument>, -{ +fn parse_argument(input: &str) -> IResult<&str, LogSegment, ()> { let parse_enclosed = delimited(char('{'), take(1u32), char('}')); let mut parse_type = map_res(parse_enclosed, move |s| match s { - "t" => Ok(LogSegment::Timestamp), "f" => Ok(LogSegment::FileName), "F" => Ok(LogSegment::FilePath), - "m" => Ok(LogSegment::ModulePath), "l" => Ok(LogSegment::LineNumber), - "L" => Ok(LogSegment::LogLevel), "s" => Ok(LogSegment::Log), - _ => Err(InvalidArgument), + "L" => Ok(LogSegment::LogLevel), + "m" => Ok(LogSegment::ModulePath), + "t" => Ok(LogSegment::Timestamp), + _ => Err(()), }); parse_type.parse(input) } -fn parse_string_segment<'a, E>(input: &'a str) -> IResult<&'a str, LogSegment, E> -where - E: ParseError<&'a str>, -{ +fn parse_string_segment(input: &str) -> IResult<&str, LogSegment, ()> { map(take_till1(|c| c == '{'), |s: &str| { LogSegment::String(s.to_string()) }) .parse(input) } -pub fn parse(input: &str) -> Result, String> { - let mut parse_all = many0(alt((parse_argument::<()>, parse_string_segment))); +pub(super) fn parse(input: &str) -> Result, String> { + let mut parse_all = many0(alt((parse_argument, parse_string_segment))); parse_all(input) .map(|(_, output)| output) @@ -89,7 +80,7 @@ mod tests { #[test] fn test_parse_string_segment() { - let result = parse_string_segment::<()>("Log: {t}"); + let result = parse_string_segment("Log: {t}"); let (input, output) = result.unwrap(); assert_eq!(input, "{t}"); assert_eq!(output, LogSegment::String("Log: ".to_string())); @@ -97,19 +88,19 @@ mod tests { #[test] fn test_parse_empty_string_segment() { - let result = parse_string_segment::<()>(""); + let result = parse_string_segment(""); assert!(result.is_err()); } #[test] fn test_parse_timestamp_argument() { - let result = parse_argument::<()>("{t}"); + let result = parse_argument("{t}"); assert_eq!(result, Ok(("", LogSegment::Timestamp))); } #[test] fn test_parse_invalid_argument() { - let result = parse_argument::<()>("{foo}"); + let result = parse_argument("{foo}"); assert_eq!(result, Result::Err(nom::Err::Error(()))); } } diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index 38cfe24d..b8070bcd 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -9,8 +9,10 @@ use std::{ sync::atomic::{AtomicUsize, Ordering}, }; -use super::format; -use super::{format::LogSegment, DefmtRecord}; +use super::{ + format::{self, LogSegment}, + DefmtRecord, +}; enum Record<'a> { Defmt(&'a DefmtRecord<'a>), From 0379d1368461319609a74fecf0711d7276845383 Mon Sep 17 00:00:00 2001 From: "Andres O. Vela" Date: Mon, 17 Jul 2023 20:54:10 +0200 Subject: [PATCH 11/20] Add host_log_format option --- decoder/src/log/json_logger.rs | 3 ++- decoder/src/log/mod.rs | 5 +++-- decoder/src/log/stdout_logger.rs | 28 +++++++++++++++++----------- print/src/main.rs | 17 +++++++++++++---- 4 files changed, 35 insertions(+), 18 deletions(-) diff --git a/decoder/src/log/json_logger.rs b/decoder/src/log/json_logger.rs index 17c25f8d..b757e72e 100644 --- a/decoder/src/log/json_logger.rs +++ b/decoder/src/log/json_logger.rs @@ -43,11 +43,12 @@ impl Log for JsonLogger { impl JsonLogger { pub fn new( log_format: Option<&str>, + host_log_format: Option<&str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) -> Box { Box::new(Self { should_log: Box::new(should_log), - host_logger: StdoutLogger::new_unboxed(log_format, |_| true), + host_logger: StdoutLogger::new_unboxed(log_format, host_log_format, |_| true), }) } diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index 84993670..17614739 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -138,14 +138,15 @@ impl<'a> DefmtRecord<'a> { /// "23124 [INFO] Location Hello, world!" pub fn init_logger( log_format: Option<&str>, + host_log_format: Option<&str>, json: bool, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) { log::set_boxed_logger(match json { - false => StdoutLogger::new(log_format, should_log), + false => StdoutLogger::new(log_format, host_log_format, should_log), true => { JsonLogger::print_schema_version(); - JsonLogger::new(log_format, should_log) + JsonLogger::new(log_format, host_log_format, should_log) } }) .unwrap(); diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index b8070bcd..ed562dc2 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -20,7 +20,8 @@ enum Record<'a> { } pub(crate) struct StdoutLogger { - format: Vec, + log_format: Vec, + host_log_format: Vec, should_log: Box bool + Sync + Send>, /// Number of characters used by the timestamp. /// This may increase over time and is used to align messages. @@ -57,25 +58,29 @@ impl Log for StdoutLogger { impl StdoutLogger { pub fn new( log_format: Option<&str>, + host_log_format: Option<&str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) -> Box { - Box::new(Self::new_unboxed(log_format, should_log)) + Box::new(Self::new_unboxed(log_format, host_log_format, should_log)) } pub fn new_unboxed( log_format: Option<&str>, + host_log_format: Option<&str>, should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static, ) -> Self { const DEFAULT_LOG_FORMAT: &str = "{t} {L} {s}\n└─ {m} @ {F}:{l}"; + const DEFAULT_HOST_LOG_FORMAT: &str = "(HOST) {L} {s}"; - let format = log_format.unwrap_or(DEFAULT_LOG_FORMAT); - let format = format::parse(format).unwrap_or_else(|_| { - // Use the default format if the user-provided format is invalid - format::parse(DEFAULT_LOG_FORMAT).unwrap() - }); + let log_format = log_format.unwrap_or(DEFAULT_LOG_FORMAT); + let log_format = format::parse(log_format).unwrap(); + + let host_log_format = host_log_format.unwrap_or(DEFAULT_HOST_LOG_FORMAT); + let host_log_format = format::parse(host_log_format).unwrap(); Self { - format, + log_format, + host_log_format, should_log: Box::new(should_log), timing_align: AtomicUsize::new(0), } @@ -86,7 +91,7 @@ impl StdoutLogger { self.timing_align.fetch_max(len, Ordering::Relaxed); let min_timestamp_width = self.timing_align.load(Ordering::Relaxed); - Printer::new(Record::Defmt(&record), &self.format) + Printer::new(Record::Defmt(&record), &self.log_format) .min_timestamp_width(min_timestamp_width) .print_frame(&mut sink) .ok(); @@ -94,7 +99,7 @@ impl StdoutLogger { pub(super) fn print_host_record(&self, record: &LogRecord, mut sink: StderrLock) { let min_timestamp_width = self.timing_align.load(Ordering::Relaxed); - Printer::new(Record::Host(record), &self.format) + Printer::new(Record::Host(record), &self.host_log_format) .min_timestamp_width(min_timestamp_width) .print_frame(&mut sink) .ok(); @@ -147,7 +152,8 @@ impl<'a> Printer<'a> { fn print_timestamp(&self, sink: &mut W) -> io::Result<()> { let timestamp = match self.record { Record::Defmt(record) => record.timestamp().to_string(), - Record::Host(_) => String::from("(HOST)"), + // TODO: Is there a timestamp for host messages? + Record::Host(_) => String::from("