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)?;