From 56d376d7bdd5b9ef40eae4b3730d34e616ecd869 Mon Sep 17 00:00:00 2001 From: Matt Ickstadt Date: Mon, 27 Sep 2021 15:25:47 -0500 Subject: [PATCH] Support multiple RTT channels --- src/cli.rs | 11 ++- src/main.rs | 188 ++++++++++++++++++++++++++++++++++++++-------------- 2 files changed, 147 insertions(+), 52 deletions(-) diff --git a/src/cli.rs b/src/cli.rs index 6a248ec8..2ec2db28 100644 --- a/src/cli.rs +++ b/src/cli.rs @@ -47,6 +47,14 @@ pub(crate) struct Opts { #[structopt(long)] pub(crate) connect_under_reset: bool, + /// Path to a trace file to write data to. + #[structopt(long, short)] + pub(crate) out_file: Option, + + /// The minimum log level of defmt messages that will be printed to stdout. + #[structopt(long, default_value = "debug")] + pub(crate) min_level: Level, + /// Enable more verbose logging. #[structopt(short, long, parse(from_occurrences))] verbose: u32, @@ -80,9 +88,10 @@ pub(crate) fn handle_arguments() -> anyhow::Result { let opts: Opts = Opts::from_args(); let verbose = opts.verbose; + let min_defmt_level = opts.min_level; defmt_decoder::log::init_logger(verbose >= 1, move |metadata| { if defmt_decoder::log::is_defmt_frame(metadata) { - true // We want to display *all* defmt frames. + metadata.level() <= min_defmt_level } else { // Log depending on how often the `--verbose` (`-v`) cli-param is supplied: // * 0: log everything from probe-run, with level "info" or higher diff --git a/src/main.rs b/src/main.rs index 1dd5e48a..c69e454f 100644 --- a/src/main.rs +++ b/src/main.rs @@ -21,7 +21,7 @@ use std::{ use anyhow::{anyhow, bail}; use colored::Colorize as _; -use defmt_decoder::{DecodeError, Frame, Locations, StreamDecoder}; +use defmt_decoder::{DecodeError, Encoding, Frame, Locations, StreamDecoder}; use probe_rs::{ flashing::{self, Format}, Core, @@ -161,7 +161,7 @@ fn start_program(sess: &mut Session, elf: &Elf) -> anyhow::Result<()> { Ok(()) } -/// Set rtt to blocking mode +/// Set rtt to blocking mode for channel 0 fn set_rtt_to_blocking( core: &mut Core, main_fn_address: u32, @@ -201,16 +201,16 @@ fn extract_and_print_logs( let exit = Arc::new(AtomicBool::new(false)); let sig_id = signal_hook::flag::register(signal::SIGINT, exit.clone())?; - let mut logging_channel = if let Some(address) = elf.rtt_buffer_address() { - Some(setup_logging_channel(address, sess.clone())?) + let logging_channels = if let Some(address) = elf.rtt_buffer_address() { + setup_logging_channels(address, sess.clone())? } else { eprintln!("RTT logs not available; blocking until the device halts.."); - None + vec![] }; - let use_defmt = logging_channel - .as_ref() - .map_or(false, |channel| channel.name() == Some("defmt")); + let use_defmt = logging_channels + .get(0) + .map_or(false, |c| c.name() == Some("defmt")); if use_defmt && opts.no_flash { bail!( @@ -220,49 +220,40 @@ fn extract_and_print_logs( bail!("\"defmt\" RTT channel is in use, but the firmware binary contains no defmt data"); } - let mut decoder_and_encoding = if use_defmt { - elf.defmt_table - .as_ref() - .map(|table| (table.new_stream_decoder(), table.encoding())) + let mut logging_channels = logging_channels + .into_iter() + .enumerate() + .map(|(i, rtt)| LogChannel::new(i, rtt, if use_defmt { &elf.defmt_table } else { &None })) + .collect::>(); + + print_separator(); + + let mut out_file = if let Some(path) = &opts.out_file { + let file = fs::OpenOptions::new() + .append(true) + .create(true) + .write(true) + .read(false) + .open(path)?; + + Some(io::BufWriter::new(file)) } else { None }; - print_separator(); - let stdout = io::stdout(); let mut stdout = stdout.lock(); - let mut read_buf = [0; 1024]; let mut was_halted = false; while !exit.load(Ordering::Relaxed) { - if let Some(logging_channel) = &mut logging_channel { - let num_bytes_read = match logging_channel.read(&mut read_buf) { - Ok(n) => n, - Err(e) => { - eprintln!("RTT error: {}", e); - break; - } - }; - - if num_bytes_read != 0 { - match decoder_and_encoding.as_mut() { - Some((stream_decoder, encoding)) => { - stream_decoder.received(&read_buf[..num_bytes_read]); - - decode_and_print_defmt_logs( - &mut **stream_decoder, - elf.defmt_locations.as_ref(), - current_dir, - opts.shorten_paths, - encoding.can_recover(), - )?; - } - - _ => { - stdout.write_all(&read_buf[..num_bytes_read])?; - stdout.flush()?; - } - } + for logging_channel in logging_channels.iter_mut().rev() { + if !logging_channel.print_all( + &mut stdout, + &mut out_file, + &elf.defmt_locations, + current_dir, + opts, + )? { + break; } } @@ -277,6 +268,7 @@ fn extract_and_print_logs( } drop(stdout); + drop(out_file); signal_hook::low_level::unregister(sig_id); signal_hook::flag::register_conditional_default(signal::SIGINT, exit.clone())?; @@ -296,7 +288,9 @@ fn extract_and_print_logs( } fn decode_and_print_defmt_logs( + number: usize, stream_decoder: &mut dyn StreamDecoder, + out_file: &mut Option>, locations: Option<&Locations>, current_dir: &Path, shorten_paths: bool, @@ -304,7 +298,7 @@ fn decode_and_print_defmt_logs( ) -> anyhow::Result<()> { loop { match stream_decoder.decode() { - Ok(frame) => forward_to_logger(&frame, locations, current_dir, shorten_paths), + Ok(frame) => forward_to_logger(number, &frame, locations, current_dir, shorten_paths, out_file), Err(DecodeError::UnexpectedEof) => break, Err(DecodeError::Malformed) => match encoding_can_recover { // if recovery is impossible, abort @@ -319,13 +313,34 @@ fn decode_and_print_defmt_logs( } fn forward_to_logger( + number: usize, frame: &Frame, locations: Option<&Locations>, current_dir: &Path, shorten_paths: bool, + out_file: &mut Option>, ) { let (file, line, mod_path) = location_info(frame, locations, current_dir, shorten_paths); defmt_decoder::log::log_defmt(frame, file.as_deref(), line, mod_path.as_deref()); + + if let Some(out_file) = out_file { + let timestamp = frame + .display_timestamp() + .map(|display| display.to_string()) + .unwrap_or_default(); + + writeln!( + out_file, + "{}|{}|{}|{}:{}|{}|{}", + timestamp, + number, + frame.level().map_or("UNKOWN", |l| l.as_str()), + file.as_deref().unwrap_or_default(), + line.map(|l| l.to_string()).unwrap_or_default(), + mod_path.unwrap_or_default(), + frame.display_message() + ).unwrap(); + } } fn location_info( @@ -355,10 +370,10 @@ fn location_info( .unwrap_or((None, None, None)) } -fn setup_logging_channel( +fn setup_logging_channels( rtt_buffer_address: u32, sess: Arc>, -) -> anyhow::Result { +) -> anyhow::Result> { const NUM_RETRIES: usize = 10; // picked at random, increase if necessary let scan_region = ScanRegion::Exact(rtt_buffer_address); @@ -367,12 +382,13 @@ fn setup_logging_channel( Ok(mut rtt) => { log::debug!("Successfully attached RTT"); - let channel = rtt - .up_channels() - .take(0) - .ok_or_else(|| anyhow!("RTT up channel 0 not found"))?; + let channels = rtt.up_channels().drain().collect::>(); + + if channels.len() == 0 { + bail!("RTT up channel 0 not found"); + } - return Ok(channel); + return Ok(channels); } Err(probe_rs_rtt::Error::ControlBlockNotFound) => { @@ -393,3 +409,73 @@ fn setup_logging_channel( fn print_separator() { println!("{}", "─".repeat(80).dimmed()); } + +struct LogChannel<'a> { + number: usize, + rtt: UpChannel, + buf: [u8; 1024], + decoder: Option<(Box, Encoding)>, +} + +impl<'a> LogChannel<'a> { + pub fn new(number: usize, rtt: UpChannel, table: &'a Option) -> Self { + Self { + number, + rtt, + buf: [0u8; 1024], + decoder: table.as_ref().map(|t| (t.new_stream_decoder(), t.encoding())), + } + } + + pub fn print_all( + &mut self, + stdout: &mut io::StdoutLock, + out_file: &mut Option>, + locations: &Option>, + current_dir: &Path, + opts: &cli::Opts, + ) -> anyhow::Result { + let Self { + number, + rtt, + buf, + decoder, + } = self; + + let num_bytes_read = match rtt.read(buf) { + Ok(n) => n, + Err(e) => { + eprintln!("RTT error: {}", e); + return Ok(false); + } + }; + + if num_bytes_read != 0 { + match decoder.as_mut() { + Some((stream_decoder, encoding)) => { + stream_decoder.received(&buf[..num_bytes_read]); + + decode_and_print_defmt_logs( + *number, + &mut **stream_decoder, + out_file, + locations.as_ref(), + current_dir, + opts.shorten_paths, + encoding.can_recover(), + )?; + } + + _ => { + stdout.write_all(&buf[..num_bytes_read])?; + stdout.flush()?; + if let Some(out_file) = out_file { + out_file.write_all(&buf[..num_bytes_read])?; + } + } + } + } + + Ok(true) + } +}