From a440ea0b4455ac0d40a96a7077814ef10a73df01 Mon Sep 17 00:00:00 2001 From: Rob Bradford Date: Tue, 28 Apr 2026 14:43:37 +0100 Subject: [PATCH] main: Create a format string parser and printer for log output Introduces a custom format string parser for use for log entries. For now only the existing format string entries are covered and the default format string matches the existing behaviour. The format string is tokenized once and then that token stream is used for each log entry. Assisted-by: Claude:Opus-4.7 Signed-off-by: Rob Bradford --- cloud-hypervisor/src/logger.rs | 145 +++++++++++++++++++++++++++------ cloud-hypervisor/src/main.rs | 13 ++- 2 files changed, 128 insertions(+), 30 deletions(-) diff --git a/cloud-hypervisor/src/logger.rs b/cloud-hypervisor/src/logger.rs index bd2b51345..145af208b 100644 --- a/cloud-hypervisor/src/logger.rs +++ b/cloud-hypervisor/src/logger.rs @@ -3,11 +3,110 @@ // SPDX-License-Identifier: Apache-2.0 // +use std::io::Write; +use std::str::FromStr; use std::sync::Mutex; +use std::time::Instant; + +use thiserror::Error; + +#[derive(Debug, Error)] +pub enum Error { + #[error("Unterminated '{{' in format string")] + UnterminatedBrace, + #[error("Unmatched '}}' in format string")] + UnmatchedBrace, + #[error("Unknown format token '{{{0}}}'")] + UnknownToken(String), +} + +enum Token { + Literal(String), + BootTime, + Thread, + Level, + Location, + Msg, +} + +impl FromStr for Token { + type Err = Error; + + fn from_str(s: &str) -> Result { + match s { + "boottime" => Ok(Self::BootTime), + "thread" => Ok(Self::Thread), + "level" => Ok(Self::Level), + "location" => Ok(Self::Location), + "msg" => Ok(Self::Msg), + _ => Err(Error::UnknownToken(s.to_string())), + } + } +} + +fn parse_format(fmt: &str) -> Result, Error> { + let mut tokens = Vec::new(); + let mut literal = String::new(); + let mut chars = fmt.chars().peekable(); + + while let Some(c) = chars.next() { + match c { + '{' => { + if chars.peek() == Some(&'{') { + chars.next(); + literal.push('{'); + continue; + } + + if !literal.is_empty() { + tokens.push(Token::Literal(std::mem::take(&mut literal))); + } + + let mut name = String::new(); + loop { + match chars.next() { + Some('}') => break, + Some(ch) => name.push(ch), + None => return Err(Error::UnterminatedBrace), + } + } + + tokens.push(name.parse()?); + } + '}' => { + if chars.peek() == Some(&'}') { + chars.next(); + literal.push('}'); + } else { + return Err(Error::UnmatchedBrace); + } + } + _ => literal.push(c), + } + } + if !literal.is_empty() { + tokens.push(Token::Literal(literal)); + } + Ok(tokens) +} + +const DEFAULT_FORMAT: &str = + "cloud-hypervisor: {boottime}s: <{thread}> {level}:{location} -- {msg}"; pub struct Logger { - pub output: Mutex>, - pub start: std::time::Instant, + output: Mutex>, + start: Instant, + tokens: Vec, +} + +impl Logger { + pub fn new(output: Box) -> Result { + Ok(Self { + output: Mutex::new(output), + start: Instant::now(), + tokens: parse_format(DEFAULT_FORMAT)?, + }) + } } impl log::Log for Logger { @@ -20,28 +119,28 @@ impl log::Log for Logger { return; } - let now = std::time::Instant::now(); - let duration = now.duration_since(self.start); - let duration_s = duration.as_secs_f32(); - - let location = if let (Some(file), Some(line)) = (record.file(), record.line()) { - format!("{file}:{line}") - } else { - record.target().to_string() - }; - + let duration_s = Instant::now().duration_since(self.start).as_secs_f32(); let mut out = self.output.lock().unwrap(); - write!( - &mut *out, - // 10: 6 decimal places + sep => whole seconds in range `0..=999` properly aligned - "cloud-hypervisor: {:>10.6?}s: <{}> {}:{} -- {}\r\n", - duration_s, - std::thread::current().name().unwrap_or("anonymous"), - record.level(), - location, - record.args(), - ) - .ok(); + for token in &self.tokens { + let _ = match token { + Token::Literal(s) => out.write_all(s.as_bytes()), + // 10: 6 decimal places + sep => whole seconds in range `0..=999` properly aligned + Token::BootTime => write!(&mut *out, "{duration_s:>10.6?}"), + Token::Thread => write!( + &mut *out, + "{}", + std::thread::current().name().unwrap_or("anonymous") + ), + Token::Level => write!(&mut *out, "{}", record.level()), + Token::Location => match (record.file(), record.line()) { + (Some(file), Some(line)) => write!(&mut *out, "{file}:{line}"), + _ => write!(&mut *out, "{}", record.target()), + }, + Token::Msg => write!(&mut *out, "{}", record.args()), + }; + } + let _ = out.write_all(b"\r\n"); } + fn flush(&self) {} } diff --git a/cloud-hypervisor/src/main.rs b/cloud-hypervisor/src/main.rs index 55484e128..5085f5683 100644 --- a/cloud-hypervisor/src/main.rs +++ b/cloud-hypervisor/src/main.rs @@ -9,7 +9,6 @@ mod test_util; use std::fs::File; use std::os::unix::io::{AsRawFd, FromRawFd, RawFd}; -use std::sync::Mutex; use std::sync::mpsc::channel; use std::{env, io}; @@ -97,6 +96,8 @@ enum Error { BareGdb, #[error("Error creating log file")] LogFileCreation(#[source] std::io::Error), + #[error("Error parsing logger format")] + LoggerFormat(#[source] logger::Error), #[error("Error setting up logger")] LoggerSetup(#[source] log::SetLoggerError), #[error("Failed to gracefully shutdown http api")] @@ -514,12 +515,10 @@ fn start_vmm( Box::new(std::io::stderr()) }; - log::set_boxed_logger(Box::new(Logger { - output: Mutex::new(log_file), - start: std::time::Instant::now(), - })) - .map(|()| log::set_max_level(log_level)) - .map_err(Error::LoggerSetup)?; + let logger = Logger::new(log_file).map_err(Error::LoggerFormat)?; + log::set_boxed_logger(Box::new(logger)) + .map(|()| log::set_max_level(log_level)) + .map_err(Error::LoggerSetup)?; let (api_request_sender, api_request_receiver) = channel(); let api_evt = EventFd::new(EFD_NONBLOCK).map_err(Error::CreateApiEventFd)?;