From 45a96debc4daca42f2daf7e7bb2b7da84837f180 Mon Sep 17 00:00:00 2001 From: Sebastian Urban Date: Sun, 3 Nov 2024 18:53:50 +0100 Subject: [PATCH] log: hide malformed message by default --- Cargo.lock | 2 +- openemc-log/Cargo.toml | 2 +- openemc-log/src/main.rs | 82 ++++++++++++++++++++++++++++++----------- 3 files changed, 62 insertions(+), 24 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 4ca5f6a..69aac14 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1201,7 +1201,7 @@ version = "0.0.0" [[package]] name = "openemc-log" -version = "0.7.0" +version = "0.7.1" dependencies = [ "anyhow", "clap", diff --git a/openemc-log/Cargo.toml b/openemc-log/Cargo.toml index 35305ab..0fff971 100644 --- a/openemc-log/Cargo.toml +++ b/openemc-log/Cargo.toml @@ -3,7 +3,7 @@ name = "openemc-log" description = "OpenEMC Logger" authors = ["Sebastian Urban "] license = "GPL-3.0" -version = "0.7.0" +version = "0.7.1" publish = false edition = "2021" diff --git a/openemc-log/src/main.rs b/openemc-log/src/main.rs index 94e9e42..2634136 100644 --- a/openemc-log/src/main.rs +++ b/openemc-log/src/main.rs @@ -44,6 +44,7 @@ use std::{ mod syslog; const READ_BUFFER_SIZE: usize = 128; +const UNPROCESSED_SIZE: usize = 16_777_216; const POLL_TIMEOUT: c_int = 60_000; const FIRMWARE_DIR: &str = "/lib/firmware"; @@ -71,6 +72,9 @@ struct Opts { /// Log to standard output instead of syslog. #[arg(short, long)] foreground: bool, + /// Show malformed log messages. + #[arg(long)] + malformed: bool, /// Gzipped ELF image of OpenEMC firmware. firmware_elf: Option, /// OpenEMC log file or device. @@ -82,30 +86,46 @@ struct Opts { probe: bool, } -/// Write defmt log message to Rust logger. -fn forward_to_logger(frame: &Frame, loc: Option<&Location>, lines: bool) { - let mut msg = String::with_capacity(256); +/// Log message for Rust logger. +#[derive(Debug, Clone, PartialEq, Eq)] +struct LogMsg { + /// Log level. + pub level: Level, + /// Message. + pub msg: String, +} - if let Some(loc) = loc { - write!(msg, "[{}", &loc.module).unwrap(); - if lines { - write!(msg, " @ {}:{}", loc.file.display(), loc.line).unwrap(); +impl LogMsg { + /// Format defmt log message for Rust logger. + pub fn from_defmt(frame: &Frame, loc: Option<&Location>, lines: bool) -> Self { + let mut msg = String::with_capacity(256); + + if let Some(loc) = loc { + write!(msg, "[{}", &loc.module).unwrap(); + if lines { + write!(msg, " @ {}:{}", loc.file.display(), loc.line).unwrap(); + } + write!(msg, "] ").unwrap(); } - write!(msg, "] ").unwrap(); - } - write!(msg, "{}", frame.display_message()).unwrap(); + write!(msg, "{}", frame.display_message()).unwrap(); - let level = match frame.level() { - Some(DefmtLevel::Error) => Level::Error, - Some(DefmtLevel::Warn) => Level::Warn, - Some(DefmtLevel::Info) => Level::Info, - Some(DefmtLevel::Debug) => Level::Debug, - Some(DefmtLevel::Trace) => Level::Trace, - None => Level::Info, - }; + let level = match frame.level() { + Some(DefmtLevel::Error) => Level::Error, + Some(DefmtLevel::Warn) => Level::Warn, + Some(DefmtLevel::Info) => Level::Info, + Some(DefmtLevel::Debug) => Level::Debug, + Some(DefmtLevel::Trace) => Level::Trace, + None => Level::Info, + }; + + Self { level, msg } + } - log::log!(level, "{msg}"); + /// Log the message to the Rust logger. + pub fn log(&self) { + log::log!(self.level, "{}", &self.msg); + } } /// Gets the log file or log device path. @@ -314,6 +334,7 @@ fn perform(opts: &Opts) -> Result { let mut buf = [0; READ_BUFFER_SIZE]; let mut stream_decoder = table.new_stream_decoder(); + let mut unprocessed = 0; while !STOP.load(Ordering::SeqCst) { // Read from start of device file. @@ -323,6 +344,7 @@ fn perform(opts: &Opts) -> Result { // Read data. match log.read(&mut buf) { + Ok(0) if unprocessed > 0 => (), Ok(0) if is_dev && !opts.oneshot && !opts.bootloader => { // Wait for data to arrive. let log_fd = log.as_fd(); @@ -334,7 +356,13 @@ fn perform(opts: &Opts) -> Result { } } Ok(0) => return Ok(true), - Ok(n) => stream_decoder.received(&buf[..n]), + Ok(n) => { + stream_decoder.received(&buf[..n]); + unprocessed += n; + if unprocessed < UNPROCESSED_SIZE { + continue; + } + } Err(err) if is_dev && err.kind() == ErrorKind::BrokenPipe => { log::warn!("======== log data was lost ========"); stream_decoder = table.new_stream_decoder(); @@ -344,11 +372,13 @@ fn perform(opts: &Opts) -> Result { } // Decode the received data. + let mut log_msgs = Vec::new(); loop { match stream_decoder.decode() { Ok(frame) => { let loc = locs.as_ref().and_then(|locs| locs.get(&frame.index())); - forward_to_logger(&frame, loc, opts.lines); + let log_msg = LogMsg::from_defmt(&frame, loc, opts.lines); + log_msgs.push(log_msg); } Err(DecodeError::UnexpectedEof) => break, Err(DecodeError::Malformed) => { @@ -356,10 +386,18 @@ fn perform(opts: &Opts) -> Result { if !table.encoding().can_recover() { return Err(DecodeError::Malformed.into()); } - break; + if !opts.malformed { + log_msgs.clear(); + } } } } + unprocessed = 0; + + // Log to system log. + for log_msg in log_msgs { + log_msg.log(); + } } Ok(false)