diff --git a/CHANGELOG.md b/CHANGELOG.md index f09a8ee3..e08fde65 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,11 +7,13 @@ and this project adheres to [Semantic Versioning](http://semver.org/). ## [Unreleased] +- [#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 +[#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 [#771]: https://github.com/knurling-rs/defmt/pull/771 diff --git a/decoder/src/log/format.rs b/decoder/src/log/format.rs index a63f4582..0cfb8654 100644 --- a/decoder/src/log/format.rs +++ b/decoder/src/log/format.rs @@ -1,41 +1,225 @@ +//! Formatting for `defmt` log frames. +//! +//! This module contains the parsers for the `defmt` custom log formatting strings. +//! +//! # Format strings +//! +//! A format string takes a set of [format specifiers] written +//! in the way a log should be printed by the logger. +//! +//! ## Basics +//! +//! Format strings allow the customization of how the logger prints logs. +//! +//! The following log will be used as reference in the examples below: +//! +//! ```ignore +//! defmt::error!("hello"); +//! ``` +//! +//! The simplest format string is `"{s}"`. This prints the log and nothing else: +//! +//! ```text +//! hello +//! ``` +//! +//! Arbitrary text can be added to the format string, which will be printed as specified with each log. +//! For example, `"Log: {s}"`: +//! +//! ```text +//! Log: hello +//! ``` +//! +//! Multiple specifiers can be included within a format string, in any order. For example `"[{L}] {s}"` prints: +//! +//! ```text +//! [ERROR] hello +//! ``` +//! +//! ## Customizing log segments +//! +//! The way a format specifier is printed can be customized by providing additional, optional [format parameters]. +//! +//! Format parameters are provided by adding the parameters after the format specifier, separated by colons (`:`), +//! like this: `"{L:bold:5} {f:white:<10} {s}"`. +//! +//! ### Color +//! +//! A log segment can be specified to be colored by providing a color in the format parameters. +//! +//! There are three different options for coloring a log segment: +//! - a string that can be parsed by the FromStr implementation of [colored::Color] (`red`, `green` etc.). +//! - `severity` colors the log segment using the predefined color for the log level of log. +//! - `werror` is similar to `severity`, but it only applies the color if the log level is WARN or ERROR. +//! +//! Only one coloring option can be provided in format parameters for a given format specifier. +//! +//! ### Styles +//! +//! A log segment can be specified to be printed with a given style by providing a style in the format parameters. +//! +//! The style specifier must be one of the following strings: +//! - `bold` +//! - `italic` +//! - `underline` +//! - `strike` +//! - `dimmed` +//! +//! Multiple styles can be applied to a single format specifier, but they must not be repeated, i.e. +//! `"{s:bold:underline:italic}"` is allowed, but `"{s:bold:bold}"` isn't. +//! +//! ### Width and alignment +//! +//! A log segment can be specified to be printed with a given minimum width and alignment by providing a format parameter. +//! +//! The alignment can be specified to be left (`<`), right (`>`), or center-aligned (`^`). +//! If no alignment is specified, left alignment is used by default. +//! +//! The minimum width is specified after the alignment. +//! For example, "{L} {f:>10}: {s}" is printed as follows: +//! +//! ```text +//! [ERROR] main.rs: hello +//! ``` +//! +//! The log level format specifier is printed with a minimum width of 5 by default. +//! +//! ## Nested formatting +//! +//! Log segments can be grouped and formatted together by nesting formats. Format parameters for the grouped log segments +//! must be provided after the group, separated by `%`. +//! +//! Nested formats allow for more intricate formatting. For example, `"{[{L:bold}]%underline} {s}"` prints +//! +//! ```text +//! [ERROR] hello +//! ``` +//! +//! where `ERROR` is formatted bold, and `[ERROR]` is underlined. +//! +//! Formats can be nested several levels. This provides a great level of flexibility to customize the logger formatting. +//! For example, the width and alignment of a group of log segments can be specified with nested formats. +//! `"{{[{L}]%bold} {f:>20}:%<35} {s}"` prints: +//! +//! ```text +//! [ERROR] main.rs: hello +//! ``` +//! +//! ## Restrictions +//! +//! - Format strings *must* include the `{s}` format specifier (log specifier). +//! - At the moment it is not possible to escape curly brackets (i.e. `{`, `}`) +//! in the format string, therefore curly brackets cannot be printed as part +//! of the logger format. +//! - The same restriction exists for the `%` character. +//! +//! [format specifiers]: LogMetadata +//! [format parameters]: LogFormat + use nom::{ branch::alt, bytes::complete::{take_till1, take_while}, character::complete::{char, digit1, one_of}, combinator::{map, map_res, opt}, multi::{many0, separated_list1}, - sequence::delimited, + sequence::{delimited, preceded}, IResult, Parser, }; use std::str::FromStr; +/// Representation of what a [LogSegment] can be. #[derive(Debug, PartialEq, Clone)] #[non_exhaustive] pub(super) enum LogMetadata { + /// `{f}` format specifier. + /// + /// For a file "src/foo/bar.rs", this option prints "bar.rs". FileName, + + /// `{F}` format specifier. + /// + /// For a file "src/foo/bar.rs", this option prints "src/foo/bar.rs". FilePath, + + /// `{l}` format specifier. + /// + /// Prints the line number where the log is coming from. LineNumber, + + /// `{s}` format specifier. + /// + /// Prints the actual log contents. + /// For `defmt::info!("hello")`, this prints "hello". Log, + + /// `{L}` format specifier. + /// + /// Prints the log level. + /// For `defmt::info!("hello")`, this prints "INFO". LogLevel, + + /// `{m}` format specifier. + /// + /// Prints the module path of the function where the log is coming from. + /// For the following log: + /// + /// ```ignore + /// // crate: my_crate + /// mod foo { + /// fn bar() { + /// defmt::info!("hello"); + /// } + /// } + /// ``` + /// this prints "my_crate::foo::bar". ModulePath, + + /// Represents the parts of the formatting string that is not specifiers. String(String), + + /// `{t}` format specifier. + /// + /// Prints the timestamp at which something was logged. + /// For a log printed with a timestamp 123456 ms, this prints "123456". Timestamp, + + /// Represents formats specified within nested curly brackets in the formatting string. + NestedLogSegments(Vec), +} + +impl LogMetadata { + /// Checks whether this `LogMetadata` came from a specifier such as + /// {t}, {f}, etc. + fn is_metadata_specifier(&self) -> bool { + !matches!( + self, + LogMetadata::String(_) | LogMetadata::NestedLogSegments(_) + ) + } } +/// Coloring options for [LogSegment]s. #[derive(Debug, PartialEq, Clone, Copy)] pub(super) enum LogColor { - /// User-defined color + /// User-defined color. + /// + /// Use a string that can be parsed by the FromStr implementation + /// of [colored::Color]. Color(colored::Color), - /// Color matching the default color for the log level + /// Color matching the default color for the log level. + /// Use `"severity"` as a format parameter to use this option. SeverityLevel, /// Color matching the default color for the log level, - /// but only if the log level is WARN or ERROR + /// but only if the log level is WARN or ERROR. + /// + /// Use `"werror"` as a format parameter to use this option. WarnError, } +/// Alignment options for [LogSegment]s. #[derive(Debug, PartialEq, Clone, Copy)] pub(super) enum Alignment { Center, @@ -43,6 +227,7 @@ pub(super) enum Alignment { Right, } +/// Representation of a segment of the formatting string. #[derive(Debug, PartialEq, Clone)] pub(super) struct LogSegment { pub(super) metadata: LogMetadata, @@ -63,6 +248,7 @@ enum IntermediateOutput { WidthAndAlignment((usize, Option)), Color(LogColor), Style(colored::Styles), + NestedLogSegment(LogSegment), } impl LogSegment { @@ -105,6 +291,56 @@ impl LogSegment { } } +/// This function is taken as-is from the parse-hyperlinks crate +/// https://docs.rs/parse-hyperlinks/0.9.3/src/parse_hyperlinks/lib.rs.html#24-68 +/// There is an open issue in nom to include this parser in nom 8.0 +/// https://github.com/rust-bakery/nom/issues/1253 +pub fn take_until_unbalanced( + opening_bracket: char, + closing_bracket: char, +) -> impl Fn(&str) -> IResult<&str, &str, ()> { + move |i: &str| { + let mut index = 0; + let mut bracket_counter = 0; + while let Some(n) = &i[index..].find(&[opening_bracket, closing_bracket, '\\'][..]) { + index += n; + let mut it = i[index..].chars(); + match it.next().unwrap_or_default() { + c if c == '\\' => { + // Skip the escape char `\`. + index += '\\'.len_utf8(); + // Skip also the following char. + let c = it.next().unwrap_or_default(); + index += c.len_utf8(); + } + c if c == opening_bracket => { + bracket_counter += 1; + index += opening_bracket.len_utf8(); + } + c if c == closing_bracket => { + // Closing bracket. + bracket_counter -= 1; + index += closing_bracket.len_utf8(); + } + // Can not happen. + _ => unreachable!(), + }; + // We found the unmatched closing bracket. + if bracket_counter == -1 { + // We do not consume it. + index -= closing_bracket.len_utf8(); + return Ok((&i[index..], &i[0..index])); + }; + } + + if bracket_counter == 0 { + Ok(("", i)) + } else { + Err(nom::Err::Error(())) + } + } +} + fn parse_metadata(input: &str) -> IResult<&str, IntermediateOutput, ()> { let mut parse_type = map_res(take_while(char::is_alphabetic), move |s| { let metadata = match s { @@ -171,22 +407,28 @@ fn parse_width_and_alignment(input: &str) -> IResult<&str, IntermediateOutput, ( )) } -fn parse_log_segment(input: &str) -> IResult<&str, LogSegment, ()> { - let (input, output) = separated_list1( - char(':'), - alt(( - parse_metadata, - parse_color, - parse_style, - parse_width_and_alignment, - )), - )(input)?; +fn parse_format(input: &str) -> IResult<&str, IntermediateOutput, ()> { + let result = alt((parse_color, parse_style, parse_width_and_alignment)).parse(input); + if !FAIL_ON_ERR { + result + } else { + match result { + Ok(r) => Ok(r), + Err(_) => Err(nom::Err::Failure(())), + } + } +} + +fn build_log_segment( + intermediate_output: Vec, +) -> Result> { let mut metadata = None; let mut color = None; let mut style = None; let mut width_and_alignment = None; - for item in output { + let mut nested_segments = None; + for item in intermediate_output { match item { IntermediateOutput::Metadata(m) if metadata.is_none() => metadata = Some(m), IntermediateOutput::Color(c) if color.is_none() => color = Some(c), @@ -204,10 +446,49 @@ fn parse_log_segment(input: &str) -> IResult<&str, LogSegment, ()> { IntermediateOutput::WidthAndAlignment(w) if width_and_alignment.is_none() => { width_and_alignment = Some(w) } + IntermediateOutput::NestedLogSegment(s) => { + let mut segments: Vec = nested_segments.unwrap_or_default(); + segments.push(s); + nested_segments = Some(segments); + } _ => return Err(nom::Err::Failure(())), } } + if NEST { + let Some(nested_segments) = nested_segments else { + return Err(nom::Err::Failure(())); + }; + + // A nested segment must have at least a valid specifier such as {t} or {f}, + // it isn't allowed to have {foo} and consider foo a string segment. + let has_metadata_specifier = nested_segments + .iter() + .any(|segment| segment.metadata.is_metadata_specifier()); + if !has_metadata_specifier { + return Err(nom::Err::Failure(())); + } + metadata = Some(LogMetadata::NestedLogSegments(nested_segments)); + } else { + // We either have nested segments, or a metadata specifier, we can't have both + // This means we either have: + // metadata specifier: {L:underline} + // nested segments specifier: {[{L:<5:bold}]%underline} + if metadata.is_some() && nested_segments.is_some() { + return Err(nom::Err::Failure(())); + } + + // If we have a nested segment there must be exactly one, + // otherwise there's something weird going on + if let Some(segments) = nested_segments { + if segments.len() == 1 { + return Ok(segments[0].clone()); + } else { + return Err(nom::Err::Failure(())); + } + } + } + let Some(metadata) = metadata else { return Err(nom::Err::Failure(())); }; @@ -216,7 +497,7 @@ fn parse_log_segment(input: &str) -> IResult<&str, LogSegment, ()> { .map(|(w, a)| (Some(w), a)) .unwrap_or((None, None)); - let log_segment = LogSegment { + Ok(LogSegment { metadata, format: LogFormat { color, @@ -224,29 +505,102 @@ fn parse_log_segment(input: &str) -> IResult<&str, LogSegment, ()> { width, alignment, }, - }; + }) +} +fn parse_log_segment(input: &str) -> IResult<&str, LogSegment, ()> { + let (input, output) = if !NEST { + separated_list1( + char(':'), + alt((parse_metadata, parse_format::, parse_nested::)), + )(input) + } else { + let parse_nested_argument = + separated_list1(char(':'), alt((parse_metadata, parse_format::))); + + let parse_nested_log_segment = map_res(parse_nested_argument, |result| { + let log_segment = build_log_segment::(result)?; + Ok::>(IntermediateOutput::NestedLogSegment( + log_segment, + )) + }); + + separated_list1( + char('%'), + alt(( + parse_nested_log_segment, + parse_format::, + parse_nested::, + )), + )(input) + }?; + + let log_segment = build_log_segment::(output)?; Ok((input, log_segment)) } -fn parse_argument(input: &str) -> IResult<&str, LogSegment, ()> { - let mut parse_enclosed = delimited(char('{'), parse_log_segment, char('}')); - parse_enclosed.parse(input) +fn parse_argument(input: &str) -> IResult<&str, LogSegment, ()> { + let take_between_matching_brackets = + delimited(char('{'), take_until_unbalanced('{', '}'), char('}')); + + take_between_matching_brackets + .and_then(parse_log_segment::) + .parse(input) } fn parse_string_segment(input: &str) -> IResult<&str, LogSegment, ()> { - map(take_till1(|c| c == '{'), |s: &str| { + map(take_till1(|c| c == '{' || c == '%'), |s: &str| { LogSegment::new(LogMetadata::String(s.to_string())) }) .parse(input) } +fn parse_nested(input: &str) -> IResult<&str, IntermediateOutput, ()> { + let parse_nested_argument = map_res(parse_argument::, |result| { + Ok::>(IntermediateOutput::NestedLogSegment(result)) + }); + let parse_nested_string_segment = map_res(parse_string_segment, |result| { + Ok::>(IntermediateOutput::NestedLogSegment(result)) + }); + let parse_nested_format = preceded(char('%'), parse_format::); + let mut parse_all = many0(alt(( + parse_nested_argument, + parse_nested_string_segment, + parse_nested_format, + ))); + + let (new_input, output) = parse_all(input)?; + let log_segment = build_log_segment::(output)?; + Ok((new_input, IntermediateOutput::NestedLogSegment(log_segment))) +} + +fn format_contains_log_specifier(segments: &[LogSegment]) -> bool { + for segment in segments { + match &segment.metadata { + LogMetadata::Log => return true, + LogMetadata::NestedLogSegments(s) => { + if format_contains_log_specifier(s) { + return true; + } + } + _ => continue, + } + } + false +} + pub(super) fn parse(input: &str) -> Result, String> { - let mut parse_all = many0(alt((parse_argument, parse_string_segment))); + let mut parse_all = many0(alt((parse_argument::, parse_string_segment))); - parse_all(input) + let result = parse_all(input) .map(|(_, output)| output) - .map_err(|e| e.to_string()) + .map_err(|e| e.to_string())?; + + if !format_contains_log_specifier(&result) { + return Err("log format must contain a `{s}` format specifier".to_string()); + } + + Ok(result) } #[cfg(test)] @@ -275,6 +629,12 @@ mod tests { assert_eq!(result, Ok(expected_output)); } + #[test] + fn test_parse_format_without_log() { + let result = parse("{t}"); + assert!(result.is_err()); + } + #[test] fn test_parse_string_segment() { let result = parse_string_segment("Log: {t}"); @@ -294,13 +654,13 @@ mod tests { #[test] fn test_parse_timestamp_argument() { - let result = parse_argument("{t}"); + let result = parse_argument::("{t}"); assert_eq!(result, Ok(("", LogSegment::new(LogMetadata::Timestamp)))); } #[test] fn test_parse_argument_with_color() { - let result = parse_log_segment("t:werror"); + let result = parse_log_segment::("t:werror"); let expected_output = LogSegment::new(LogMetadata::Timestamp).with_color(LogColor::WarnError); assert_eq!(result, Ok(("", expected_output))); @@ -308,7 +668,7 @@ mod tests { #[test] fn test_parse_argument_with_extra_format_parameters_width_first() { - let result = parse_argument("{t:>8:white}"); + let result = parse_argument::("{t:>8:white}"); let expected_output = LogSegment::new(LogMetadata::Timestamp) .with_width(8) .with_alignment(Alignment::Right) @@ -318,7 +678,7 @@ mod tests { #[test] fn test_parse_argument_with_extra_format_parameters_color_first() { - let result = parse_argument("{f:werror:<25}"); + let result = parse_argument::("{f:werror:<25}"); let expected_output = LogSegment::new(LogMetadata::FileName) .with_width(25) .with_alignment(Alignment::Left) @@ -328,8 +688,8 @@ mod tests { #[test] fn test_parse_invalid_argument() { - let result = parse_argument("{foo}"); - assert_eq!(result, Result::Err(nom::Err::Error(()))); + let result = parse_argument::("{foo}"); + assert!(result.is_err()); } #[test] @@ -414,4 +774,89 @@ mod tests { let result = parse(log_template); assert!(result.is_err()); } + + #[test] + fn test_parse_single_nested_format() { + let log_template = "{[{L:<5:bold}]%underline%italic} {s}"; + let expected_output = vec![ + LogSegment::new(LogMetadata::NestedLogSegments(vec![ + LogSegment::new(LogMetadata::String("[".to_string())), + LogSegment::new(LogMetadata::LogLevel) + .with_alignment(Alignment::Left) + .with_width(5) + .with_style(colored::Styles::Bold), + LogSegment::new(LogMetadata::String("]".to_string())), + ])) + .with_style(colored::Styles::Underline) + .with_style(colored::Styles::Italic), + LogSegment::new(LogMetadata::String(" ".to_string())), + LogSegment::new(LogMetadata::Log), + ]; + let result = parse(log_template); + assert_eq!(result, Ok(expected_output)); + } + + #[test] + fn test_parse_single_nested_format_with_bad_specifier() { + let log_template = "{[{L:<5:bold}]%bad%underline} {s}"; + let result = parse(log_template); + assert!(result.is_err()); + } + + #[test] + fn test_parse_double_nested_format() { + let log_template = "{{[{L:<5}]%bold} {f:>20}:%<30} {s}"; + let expected_output = vec![ + LogSegment::new(LogMetadata::NestedLogSegments(vec![ + LogSegment::new(LogMetadata::NestedLogSegments(vec![ + LogSegment::new(LogMetadata::String("[".to_string())), + LogSegment::new(LogMetadata::LogLevel) + .with_alignment(Alignment::Left) + .with_width(5), + LogSegment::new(LogMetadata::String("]".to_string())), + ])) + .with_style(colored::Styles::Bold), + LogSegment::new(LogMetadata::String(" ".to_string())), + LogSegment::new(LogMetadata::FileName) + .with_alignment(Alignment::Right) + .with_width(20), + LogSegment::new(LogMetadata::String(":".to_string())), + ])) + .with_alignment(Alignment::Left) + .with_width(30), + LogSegment::new(LogMetadata::String(" ".to_string())), + LogSegment::new(LogMetadata::Log), + ]; + let result = parse(log_template); + assert_eq!(result, Ok(expected_output)); + } + + #[test] + fn test_parse_triple_nested_format() { + let log_template = "{{{[{L:<5}]%bold} {f:>20}:%<30} {s}%werror}"; + let expected_output = vec![LogSegment::new(LogMetadata::NestedLogSegments(vec![ + LogSegment::new(LogMetadata::NestedLogSegments(vec![ + LogSegment::new(LogMetadata::NestedLogSegments(vec![ + LogSegment::new(LogMetadata::String("[".to_string())), + LogSegment::new(LogMetadata::LogLevel) + .with_alignment(Alignment::Left) + .with_width(5), + LogSegment::new(LogMetadata::String("]".to_string())), + ])) + .with_style(colored::Styles::Bold), + LogSegment::new(LogMetadata::String(" ".to_string())), + LogSegment::new(LogMetadata::FileName) + .with_alignment(Alignment::Right) + .with_width(20), + LogSegment::new(LogMetadata::String(":".to_string())), + ])) + .with_alignment(Alignment::Left) + .with_width(30), + LogSegment::new(LogMetadata::String(" ".to_string())), + LogSegment::new(LogMetadata::Log), + ])) + .with_color(LogColor::WarnError)]; + let result = parse(log_template); + assert_eq!(result, Ok(expected_output)); + } } diff --git a/decoder/src/log/stdout_logger.rs b/decoder/src/log/stdout_logger.rs index 1e3ff12c..0b0997ee 100644 --- a/decoder/src/log/stdout_logger.rs +++ b/decoder/src/log/stdout_logger.rs @@ -147,6 +147,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 { self.min_timestamp_width = min_timestamp_width; self @@ -155,41 +156,64 @@ 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 { - match &segment.metadata { - LogMetadata::String(s) => self.print_string(sink, s), - LogMetadata::Timestamp => self.print_timestamp(sink, &segment.format), - LogMetadata::FileName => self.print_file_name(sink, &segment.format), - LogMetadata::FilePath => self.print_file_path(sink, &segment.format), - LogMetadata::ModulePath => self.print_module_path(sink, &segment.format), - LogMetadata::LineNumber => self.print_line_number(sink, &segment.format), - LogMetadata::LogLevel => self.print_log_level(sink, &segment.format), - LogMetadata::Log => self.print_log(sink, &segment.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) + } + }; + + write!(sink, "{s}")?; } writeln!(sink) } - fn print_string(&self, sink: &mut W, s: &str) -> io::Result<()> { - write!(sink, "{s}") + fn build_nested(&self, segments: &[LogSegment], format: &LogFormat) -> String { + let mut result = String::new(); + for segment in segments { + 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) + } + }; + result.push_str(&s); + } + + build_formatted_string(&result, format, 0, self.record_log_level(), format.color) } - fn print_timestamp(&self, sink: &mut W, format: &LogFormat) -> io::Result<()> { + fn build_timestamp(&self, format: &LogFormat) -> String { let s = match self.record { Record::Defmt(record) if !record.timestamp().is_empty() => record.timestamp(), _ => "