diff --git a/CHANGELOG.md b/CHANGELOG.md index d01a2b39..dd14ba38 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,9 +7,17 @@ and this project adheres to [Semantic Versioning](http://semver.org/). ## [Unreleased] +- [#771]: `defmt-macros`: Ignore empty items in DEFMT_LOG + +[#771]: https://github.com/knurling-rs/defmt/pull/771 + +## defmt-decoder v0.3.8, defmt-print v0.3.8 - 2023-08-01 + - [#766] `decoder::log`: Rename `PrettyLogger` to `StdoutLogger` +- [#765]: `defmt-decoder`: Add support for customizable logger formatting [#766]: https://github.com/knurling-rs/defmt/pull/766 +[#765]: https://github.com/knurling-rs/defmt/pull/765 ## [v0.3.5] - 2023-06-19 diff --git a/decoder/Cargo.toml b/decoder/Cargo.toml index 793bf972..f5479eeb 100644 --- a/decoder/Cargo.toml +++ b/decoder/Cargo.toml @@ -7,13 +7,14 @@ license = "MIT OR Apache-2.0" name = "defmt-decoder" readme = "../README.md" repository = "https://github.com/knurling-rs/defmt" -version = "0.3.7" +version = "0.3.8" [dependencies] 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 = [ @@ -34,7 +35,7 @@ gimli = { version = "0.27", default-features = false, features = [ "read", "std", ] } -object = { version = "0.30", default-features = false, features = [ +object = { version = "0.31", default-features = false, features = [ "read_core", "elf", "std", diff --git a/decoder/src/lib.rs b/decoder/src/lib.rs index cf7fa122..7da00bf2 100644 --- a/decoder/src/lib.rs +++ b/decoder/src/lib.rs @@ -271,6 +271,10 @@ impl Table { pub fn encoding(&self) -> Encoding { self.encoding } + + pub fn has_timestamp(&self) -> bool { + self.timestamp.is_some() + } } // NOTE follows `parser::Type` diff --git a/decoder/src/log/format.rs b/decoder/src/log/format.rs new file mode 100644 index 00000000..428799fa --- /dev/null +++ b/decoder/src/log/format.rs @@ -0,0 +1,106 @@ +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(super) enum LogSegment { + FileName, + FilePath, + LineNumber, + Log, + LogLevel, + ModulePath, + String(String), + Timestamp, +} + +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 { + "f" => Ok(LogSegment::FileName), + "F" => Ok(LogSegment::FilePath), + "l" => Ok(LogSegment::LineNumber), + "s" => Ok(LogSegment::Log), + "L" => Ok(LogSegment::LogLevel), + "m" => Ok(LogSegment::ModulePath), + "t" => Ok(LogSegment::Timestamp), + _ => Err(()), + }); + + parse_type.parse(input) +} + +fn parse_string_segment(input: &str) -> IResult<&str, LogSegment, ()> { + map(take_till1(|c| c == '{'), |s: &str| { + LogSegment::String(s.to_string()) + }) + .parse(input) +} + +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) + .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}"); + 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..3e9d0ec8 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::{DefmtLoggerInfo, DefmtRecord, StdoutLogger}; pub(crate) struct JsonLogger { should_log: Box bool + Sync + Send>, @@ -41,10 +41,14 @@ impl Log for JsonLogger { } impl JsonLogger { - pub fn new(should_log: impl Fn(&Metadata) -> bool + Sync + Send + 'static) -> Box { + 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(true, |_| true), + host_logger: StdoutLogger::new_unboxed(log_format, host_log_format, |_| true), }) } @@ -53,6 +57,10 @@ impl JsonLogger { serde_json::to_writer(&mut sink, &SCHEMA_VERSION).ok(); writeln!(sink).ok(); } + + pub fn info(&self) -> DefmtLoggerInfo { + self.host_logger.info() + } } /// Create a new [JsonFrame] from a log-frame from the target diff --git a/decoder/src/log/mod.rs b/decoder/src/log/mod.rs index 1d01d571..08dd699b 100644 --- a/decoder/src/log/mod.rs +++ b/decoder/src/log/mod.rs @@ -6,10 +6,11 @@ //! [`log`]: https://crates.io/crates/log //! [`defmt`]: https://crates.io/crates/defmt +mod format; mod json_logger; mod stdout_logger; -use log::{Level, LevelFilter, Metadata, Record}; +use log::{Level, LevelFilter, Log, Metadata, Record}; use serde::{Deserialize, Serialize}; use std::fmt; @@ -119,21 +120,53 @@ impl<'a> DefmtRecord<'a> { /// The caller has to provide a `should_log` closure that determines whether a log record should be /// printed. /// -/// 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). +/// 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}" +/// +/// The arguments between curly braces are placeholders for log metadata. +/// The following arguments are supported: +/// - {f} : file name (e.g. "main.rs") +/// - {F} : file path (e.g. "src/bin/main.rs") +/// - {l} : line number +/// - {L} : log level (e.g. "INFO", "DEBUG", etc) +/// - {m} : module path (e.g. "foo::bar::some_function") +/// - {s} : the actual log +/// - {t} : log timestamp +/// +/// For example, with the log format shown above, a log would look like this: +/// "23124 [INFO] Location Hello, world!" pub fn init_logger( - always_include_location: bool, + 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(always_include_location, should_log), +) -> DefmtLoggerInfo { + let (logger, info): (Box, DefmtLoggerInfo) = match json { + false => { + let logger = StdoutLogger::new(log_format, host_log_format, should_log); + let info = logger.info(); + (logger, info) + } true => { JsonLogger::print_schema_version(); - JsonLogger::new(should_log) + let logger = JsonLogger::new(log_format, host_log_format, should_log); + let info = logger.info(); + (logger, info) } - }) - .unwrap(); + }; + log::set_boxed_logger(logger).unwrap(); log::set_max_level(LevelFilter::Trace); + info +} + +#[derive(Clone, Copy)] +pub struct DefmtLoggerInfo { + has_timestamp: bool, +} + +impl DefmtLoggerInfo { + pub fn has_timestamp(&self) -> bool { + self.has_timestamp + } } diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index ff125de1..d87a6a82 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -1,20 +1,30 @@ -use colored::{Color, Colorize}; +use colored::{Color, ColoredString, 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}, + io::{self, StderrLock, StdoutLock}, + path::Path, sync::atomic::{AtomicUsize, Ordering}, }; -use super::DefmtRecord; +use super::{ + format::{self, LogSegment}, + DefmtLoggerInfo, DefmtRecord, +}; + +enum Record<'a> { + Defmt(&'a DefmtRecord<'a>), + Host(&'a LogRecord<'a>), +} pub(crate) struct StdoutLogger { - always_include_location: bool, + 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. + /// Number of characters used by the timestamp. + /// This may increase over time and is used to align messages. timing_align: AtomicUsize, } @@ -23,7 +33,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 +42,11 @@ 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), - }; + if record.level().is_some() { + self.print_defmt_record(record, sink); + } else { + self.print_defmt_record_without_format(record, sink); + } } None => { // non-defmt logs go to stderr @@ -51,150 +61,202 @@ impl Log for StdoutLogger { impl StdoutLogger { pub fn new( - always_include_location: bool, + log_format: Option<&str>, + host_log_format: Option<&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, host_log_format, should_log)) } pub fn new_unboxed( - always_include_location: bool, + 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 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 { - always_include_location, + log_format, + host_log_format, should_log: Box::new(should_log), timing_align: AtomicUsize::new(0), } } - fn print_defmt_record(&self, record: DefmtRecord, level: Level, mut sink: StdoutLock) { + pub fn info(&self) -> DefmtLoggerInfo { + let has_timestamp = self.log_format.contains(&LogSegment::Timestamp); + DefmtLoggerInfo { has_timestamp } + } + + 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.log_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) { - 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(), - ) + pub(super) fn print_defmt_record_without_format( + &self, + record: DefmtRecord, + mut sink: StdoutLock, + ) { + const RAW_FORMAT: &[LogSegment] = &[LogSegment::Log]; + Printer::new(Record::Defmt(&record), RAW_FORMAT) + .print_frame(&mut sink) .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(), - ) - .ok(); + 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.host_log_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!( - sink, - "{timestamp:>0$}{spacing}{level:5} {args}", - self.min_timestamp_width, - timestamp = self.record.timestamp(), - spacing = if self.record.timestamp().is_empty() { - "" + /// 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) + } + + 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) => { + if record.timestamp().is_empty() { + String::from("