Merge pull request #423 from andresovela/auto-timestamping

Add better defaults for log format when timestamp is available
knurling-rs · Sep 27, 2023 · 0fc0d67 · 0fc0d67
2 parents fd812a9 + ebdbe94
commit 0fc0d67
Show file tree

Hide file tree

Showing 3 changed files with 70 additions and 61 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -6,6 +6,10 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/) and this p
 
 ## [Unreleased]
 
+- [#423] Add better defaults for log format when timestamp is available
+
+[#423]: https://github.com/knurling-rs/probe-run/pull/423
+
 ## [v0.3.10] - 2023-08-01
 
 - [#417] Release `probe-run v0.3.10`

diff --git a/src/cli.rs b/src/cli.rs
@@ -3,7 +3,6 @@ use std::path::PathBuf;
 use clap::{ArgAction, Parser};
 use defmt_decoder::DEFMT_VERSIONS;
 use git_version::git_version;
-use log::Level;
 use probe_rs::Probe;
 
 use crate::probe;
@@ -127,45 +126,6 @@ const HELPER_CMDS: [&str; 3] = ["list_chips", "list_probes", "version"];
 
 pub fn handle_arguments() -> anyhow::Result<i32> {
     let opts = Opts::parse();
-    let verbose = opts.verbose;
-    let mut log_format = opts.log_format.as_deref();
-    let mut host_log_format = opts.host_log_format.as_deref();
-
-    const DEFAULT_LOG_FORMAT: &str = "{L} {s}\n└─ {m} @ {F}:{l}";
-    const DEFAULT_HOST_LOG_FORMAT: &str = "(HOST) {L} {s}";
-    const DEFAULT_VERBOSE_HOST_LOG_FORMAT: &str = "(HOST) {L} {s}\n└─ {m} @ {F}:{l}";
-
-    if log_format.is_none() {
-        log_format = Some(DEFAULT_LOG_FORMAT);
-    }
-
-    if host_log_format.is_none() {
-        if verbose == 0 {
-            host_log_format = Some(DEFAULT_HOST_LOG_FORMAT);
-        } else {
-            host_log_format = Some(DEFAULT_VERBOSE_HOST_LOG_FORMAT);
-        }
-    }
-
-    let logger_info =
-        defmt_decoder::log::init_logger(log_format, host_log_format, opts.json, move |metadata| {
-            if defmt_decoder::log::is_defmt_frame(metadata) {
-                true // We want to display *all* defmt frames.
-            } else {
-                // Log depending on how often the `--verbose` (`-v`) cli-param is supplied:
-                //   * 0: log everything from probe-run, with level "info" or higher
-                //   * 1: log everything from probe-run
-                //   * 2 or more: log everything
-                match verbose {
-                    0 => {
-                        metadata.target().starts_with("probe_run")
-                            && metadata.level() <= Level::Info
-                    }
-                    1 => metadata.target().starts_with("probe_run"),
-                    _ => true,
-                }
-            }
-        });
 
     if opts.measure_stack {
         log::warn!("use of deprecated option `--measure-stack`: Has no effect and will vanish on next breaking release")
@@ -181,7 +141,7 @@ pub fn handle_arguments() -> anyhow::Result<i32> {
         print_chips();
         Ok(EXIT_SUCCESS)
     } else if let (Some(elf), Some(chip)) = (opts.elf.as_deref(), opts.chip.as_deref()) {
-        crate::run_target_program(elf, chip, &opts, logger_info)
+        crate::run_target_program(elf, chip, &opts)
     } else {
         unreachable!("due to `StructOpt` constraints")
     }

diff --git a/src/main.rs b/src/main.rs
@@ -23,7 +23,8 @@ use std::{
 
 use anyhow::{anyhow, bail};
 use colored::Colorize as _;
-use defmt_decoder::{log::DefmtLoggerInfo, DecodeError, Frame, Locations, StreamDecoder};
+use defmt_decoder::{DecodeError, Frame, Locations, StreamDecoder};
+use log::Level;
 use probe_rs::{
     config::MemoryRegion,
     flashing::{self, Format},
@@ -43,19 +44,19 @@ use crate::{
 
 const TIMEOUT: Duration = Duration::from_secs(1);
 
+const DEFAULT_LOG_FORMAT_WITH_TIMESTAMP: &str = "{t} {L} {s}\n└─ {m} @ {F}:{l}";
+const DEFAULT_LOG_FORMAT_WITHOUT_TIMESTAMP: &str = "{L} {s}\n└─ {m} @ {F}:{l}";
+const DEFAULT_HOST_LOG_FORMAT: &str = "(HOST) {L} {s}";
+const DEFAULT_VERBOSE_HOST_LOG_FORMAT: &str = "(HOST) {L} {s}\n└─ {m} @ {F}:{l}";
+
 fn main() -> anyhow::Result<()> {
     configure_terminal_colorization();
 
     #[allow(clippy::redundant_closure)]
     cli::handle_arguments().map(|code| process::exit(code))
 }
 
-fn run_target_program(
-    elf_path: &Path,
-    chip_name: &str,
-    opts: &cli::Opts,
-    logger_info: DefmtLoggerInfo,
-) -> anyhow::Result<i32> {
+fn run_target_program(elf_path: &Path, chip_name: &str, opts: &cli::Opts) -> anyhow::Result<i32> {
     // connect to probe and flash firmware
     let probe_target = lookup_probe_target(elf_path, chip_name, opts)?;
     let mut sess = attach_to_probe(probe_target.clone(), opts)?;
@@ -75,22 +76,66 @@ fn run_target_program(
     let elf = &Elf::parse(&elf_bytes, elf_path, reset_fn_address)?;
     let target_info = TargetInfo::new(elf, memory_map, probe_target, stack_start)?;
 
-    if let Some(table) = &elf.defmt_table {
-        if logger_info.has_timestamp() && !table.has_timestamp() {
-            log::warn!(
-                "logger format contains timestamp but no timestamp implementation \
-                was provided; consider removing the timestamp `{{t}}` from the \
-                logger format  or provide a `defmt::timestamp!` implementation"
-            );
-        } else if !logger_info.has_timestamp() && table.has_timestamp() {
-            log::warn!(
-                "`defmt::timestamp!` implementation was found, but timestamp is not \
-                part of the log format; consider adding the timestamp `{{t}}` \
-                argument to the log format"
-            );
+    let verbose = opts.verbose;
+    let is_timestamping_available = if let Some(table) = &elf.defmt_table {
+        table.has_timestamp()
+    } else {
+        false
+    };
+
+    let mut log_format = opts.log_format.as_deref();
+    let mut host_log_format = opts.host_log_format.as_deref();
+
+    if log_format.is_none() {
+        log_format = if is_timestamping_available {
+            Some(DEFAULT_LOG_FORMAT_WITH_TIMESTAMP)
+        } else {
+            Some(DEFAULT_LOG_FORMAT_WITHOUT_TIMESTAMP)
+        };
+    }
+
+    if host_log_format.is_none() {
+        if verbose == 0 {
+            host_log_format = Some(DEFAULT_HOST_LOG_FORMAT);
+        } else {
+            host_log_format = Some(DEFAULT_VERBOSE_HOST_LOG_FORMAT);
         }
     }
 
+    let logger_info =
+        defmt_decoder::log::init_logger(log_format, host_log_format, opts.json, move |metadata| {
+            if defmt_decoder::log::is_defmt_frame(metadata) {
+                true // We want to display *all* defmt frames.
+            } else {
+                // Log depending on how often the `--verbose` (`-v`) cli-param is supplied:
+                //   * 0: log everything from probe-run, with level "info" or higher
+                //   * 1: log everything from probe-run
+                //   * 2 or more: log everything
+                match verbose {
+                    0 => {
+                        metadata.target().starts_with("probe_run")
+                            && metadata.level() <= Level::Info
+                    }
+                    1 => metadata.target().starts_with("probe_run"),
+                    _ => true,
+                }
+            }
+        });
+
+    if logger_info.has_timestamp() && !is_timestamping_available {
+        log::warn!(
+            "logger format contains timestamp but no timestamp implementation \
+            was provided; consider removing the timestamp `{{t}}` from the \
+            logger format  or provide a `defmt::timestamp!` implementation"
+        );
+    } else if !logger_info.has_timestamp() && is_timestamping_available {
+        log::warn!(
+            "`defmt::timestamp!` implementation was found, but timestamp is not \
+            part of the log format; consider adding the timestamp `{{t}}` \
+            argument to the log format"
+        );
+    }
+
     // install stack canary
     let canary = Canary::install(core, elf, &target_info)?;
     if canary.is_none() {