diff --git a/Cargo.toml b/Cargo.toml index e07713a..7e44739 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -36,7 +36,7 @@ prost-types = "0.12" serde = { version = "1.0", features = ["derive"] } serde_json = "1.0" thiserror = "1.0" -time = { version = "0.3.7", features = ["serde", "std"] } +time = { version = "0.3.29", features = ["serde", "std", "formatting"] } tokio = "1.26" tonic = "0.10" tonic-build = "0.10" diff --git a/crates/shim/src/logger.rs b/crates/shim/src/logger.rs index 81275e3..0d0becc 100644 --- a/crates/shim/src/logger.rs +++ b/crates/shim/src/logger.rs @@ -24,6 +24,7 @@ use std::{ }; use log::{Metadata, Record}; +use time::{format_description::well_known::Rfc3339, OffsetDateTime}; use crate::error::Error; #[cfg(windows)] @@ -68,7 +69,13 @@ impl log::Log for FifoLogger { // a write(2) will cause a SIGPIPE signal to be generated for the calling process. // If the calling process is ignoring this signal, then write(2) fails with the error // EPIPE. - let _ = writeln!(guard.borrow_mut(), "[{}] {}", record.level(), record.args()); + let _ = writeln!( + guard.borrow_mut(), + "time=\"{}\" level={} {}\n", + rfc3339_formated(), + record.level().as_str().to_lowercase(), + record.args() + ); } } @@ -103,6 +110,12 @@ pub fn init(debug: bool, _namespace: &str, _id: &str) -> Result<(), Error> { Ok(()) } +pub(crate) fn rfc3339_formated() -> String { + OffsetDateTime::now_utc() + .format(&Rfc3339) + .unwrap_or(OffsetDateTime::now_utc().to_string()) +} + #[cfg(test)] mod tests { use log::{Log, Record}; diff --git a/crates/shim/src/sys/windows/named_pipe_logger.rs b/crates/shim/src/sys/windows/named_pipe_logger.rs index bc6719e..64b7ea2 100644 --- a/crates/shim/src/sys/windows/named_pipe_logger.rs +++ b/crates/shim/src/sys/windows/named_pipe_logger.rs @@ -23,6 +23,8 @@ use std::{ use log::{Metadata, Record}; use mio::{windows::NamedPipe, Events, Interest, Poll, Token}; +use crate::logger; + pub struct NamedPipeLogger { current_connection: Arc>, } @@ -82,7 +84,12 @@ impl log::Log for NamedPipeLogger { fn log(&self, record: &Record) { if self.enabled(record.metadata()) { - let message = format!("[{}] {}\n", record.level(), record.args()); + let message = format!( + "time=\"{}\" level={} {}\n", + logger::rfc3339_formated(), + record.level().as_str().to_lowercase(), + record.args() + ); match self .current_connection @@ -175,8 +182,14 @@ mod tests { logger.log(&record); logger.flush(); - let buf = read_message(&mut client); - assert_eq!("[INFO] hello", std::str::from_utf8(&buf).unwrap()); + let buf = read_message(&mut client, 53); + let message = std::str::from_utf8(&buf).unwrap(); + assert!(message.starts_with("time=\""), "message was: {:?}", message); + assert!( + message.ends_with("level=info hello\n"), + "message was: {:?}", + message + ); // test that we can reconnect after a reader disconnects // we need to get the raw handle and drop that as well to force full disconnect @@ -192,16 +205,16 @@ mod tests { logger.log(&record); logger.flush(); - read_message(&mut client2); + read_message(&mut client2, 51); } - fn read_message(client: &mut NamedPipe) -> [u8; 12] { + fn read_message(client: &mut NamedPipe, length: usize) -> Vec { let mut poll = Poll::new().unwrap(); poll.registry() .register(client, Token(1), Interest::READABLE) .unwrap(); let mut events = Events::with_capacity(128); - let mut buf = [0; 12]; + let mut buf = vec![0; length]; loop { poll.poll(&mut events, Some(Duration::from_millis(10))) .unwrap(); @@ -221,7 +234,7 @@ mod tests { Err(e) => panic!("Error reading from pipe: {}", e), } } - buf + buf.to_vec() } fn create_client(pipe_name: &str) -> mio::windows::NamedPipe {