diff --git a/client/cli/src/config.rs b/client/cli/src/config.rs index 0c3bf98a2f5db..7d74328487937 100644 --- a/client/cli/src/config.rs +++ b/client/cli/src/config.rs @@ -554,6 +554,11 @@ pub trait CliConfiguration: Sized { Ok(self.shared_params().disable_log_color()) } + /// Should use UTC time in log output? + fn use_utc_log_time(&self) -> Result { + Ok(self.shared_params().use_utc_log_time()) + } + /// Initialize substrate. This must be done only once per process. /// /// This method: @@ -608,6 +613,10 @@ pub trait CliConfiguration: Sized { logger.with_colors(false); } + if self.use_utc_log_time()? { + logger.with_utc(true); + } + // Call hook for custom profiling setup. logger_hook(&mut logger, config); diff --git a/client/cli/src/params/shared_params.rs b/client/cli/src/params/shared_params.rs index 3d20ca504a691..5ebb573873897 100644 --- a/client/cli/src/params/shared_params.rs +++ b/client/cli/src/params/shared_params.rs @@ -56,6 +56,10 @@ pub struct SharedParams { #[arg(long)] pub disable_log_color: bool, + /// Use UTC time in log output. + #[arg(long)] + pub use_utc_log_time: bool, + /// Enable feature to dynamically update and reload the log filter. /// Be aware that enabling this feature can lead to a performance decrease up to factor six or /// more. Depending on the global logging level the performance decrease changes. @@ -114,7 +118,12 @@ impl SharedParams { /// Should the log color output be disabled? pub fn disable_log_color(&self) -> bool { - self.disable_log_color + std::env::var("NO_COLOR").map_or(self.disable_log_color, |no_color| no_color == "1") + } + + /// Should use UTC time in log output? + pub fn use_utc_log_time(&self) -> bool { + self.use_utc_log_time } /// Is log reloading enabled diff --git a/client/tracing/src/logging/event_format.rs b/client/tracing/src/logging/event_format.rs index f4579f006c25d..7fbea5f094070 100644 --- a/client/tracing/src/logging/event_format.rs +++ b/client/tracing/src/logging/event_format.rs @@ -16,7 +16,6 @@ // You should have received a copy of the GNU General Public License // along with this program. If not, see . -use crate::logging::fast_local_time::FastLocalTime; use ansi_term::Colour; use regex::Regex; use std::fmt::{self, Write}; @@ -30,9 +29,9 @@ use tracing_subscriber::{ }; /// A pre-configured event formatter. -pub struct EventFormat { +pub struct EventFormat { /// Use the given timer for log message timestamps. - pub timer: T, + pub timer: Box, /// Sets whether or not an event's target is displayed. pub display_target: bool, /// Sets whether or not an event's level is displayed. @@ -45,17 +44,14 @@ pub struct EventFormat { pub dup_to_stdout: bool, } -impl EventFormat -where - T: FormatTime, -{ +impl EventFormat { // NOTE: the following code took inspiration from tracing-subscriber // // https://github.com/tokio-rs/tracing/blob/2f59b32/tracing-subscriber/src/fmt/format/mod.rs#L449 pub(crate) fn format_event_custom<'b, S, N>( &self, ctx: CustomFmtContext<'b, S, N>, - writer: &mut dyn fmt::Write, + writer: &mut dyn Write, event: &Event, ) -> fmt::Result where @@ -65,7 +61,7 @@ where let writer = &mut ControlCodeSanitizer::new(!self.enable_color, writer); let normalized_meta = event.normalized_metadata(); let meta = normalized_meta.as_ref().unwrap_or_else(|| event.metadata()); - time::write(&self.timer, writer, self.enable_color)?; + time::write(&*self.timer, writer, self.enable_color)?; if self.display_level { let fmt_level = { FmtLevel::new(meta.level(), self.enable_color) }; @@ -118,16 +114,15 @@ where // NOTE: the following code took inspiration from tracing-subscriber // // https://github.com/tokio-rs/tracing/blob/2f59b32/tracing-subscriber/src/fmt/format/mod.rs#L449 -impl FormatEvent for EventFormat +impl FormatEvent for EventFormat where S: Subscriber + for<'a> LookupSpan<'a>, N: for<'a> FormatFields<'a> + 'static, - T: FormatTime, { fn format_event( &self, ctx: &FmtContext, - writer: &mut dyn fmt::Write, + writer: &mut dyn Write, event: &Event, ) -> fmt::Result { if self.dup_to_stdout && @@ -239,9 +234,9 @@ mod time { use std::fmt; use tracing_subscriber::fmt::time::FormatTime; - pub(crate) fn write(timer: T, writer: &mut dyn fmt::Write, with_ansi: bool) -> fmt::Result + pub(crate) fn write(timer: &T, writer: &mut dyn fmt::Write, with_ansi: bool) -> fmt::Result where - T: FormatTime, + T: FormatTime + ?Sized, { if with_ansi { let style = Style::new().dimmed(); diff --git a/client/tracing/src/logging/mod.rs b/client/tracing/src/logging/mod.rs index a3cf277fbd501..ebe96ad0bec62 100644 --- a/client/tracing/src/logging/mod.rs +++ b/client/tracing/src/logging/mod.rs @@ -28,7 +28,7 @@ mod fast_local_time; mod layers; mod stderr_writer; -pub(crate) type DefaultLogger = stderr_writer::MakeStderrWriter; +pub(crate) type DefaultLogger = MakeStderrWriter; pub use directives::*; pub use sc_tracing_proc_macro::*; @@ -38,10 +38,11 @@ use tracing::Subscriber; use tracing_subscriber::{ filter::LevelFilter, fmt::{ - format, FormatEvent, FormatFields, Formatter, Layer as FmtLayer, MakeWriter, - SubscriberBuilder, + format, + time::{ChronoUtc, FormatTime}, + FormatEvent, FormatFields, Formatter, Layer as FmtLayer, MakeWriter, SubscriberBuilder, }, - layer::{self, SubscriberExt}, + layer::SubscriberExt, registry::LookupSpan, EnvFilter, FmtSubscriber, Layer, Registry, }; @@ -95,6 +96,7 @@ fn prepare_subscriber( directives: &str, profiling_targets: Option<&str>, force_colors: Option, + use_utc: bool, detailed_output: bool, builder_hook: impl Fn( SubscriberBuilder, @@ -104,8 +106,8 @@ where N: for<'writer> FormatFields<'writer> + 'static, E: FormatEvent + 'static, W: MakeWriter + 'static, - F: layer::Layer> + Send + Sync + 'static, - FmtLayer: layer::Layer + Send + Sync + 'static, + F: Layer> + Send + Sync + 'static, + FmtLayer: Layer + Send + Sync + 'static, { // Accept all valid directives and print invalid ones fn parse_user_directives(mut env_filter: EnvFilter, dirs: &str) -> Result { @@ -166,12 +168,16 @@ where // If we're only logging `INFO` entries then we'll use a simplified logging format. let detailed_output = match max_level_hint { - Some(level) if level <= tracing_subscriber::filter::LevelFilter::INFO => false, + Some(level) if level <= LevelFilter::INFO => false, _ => true, } || detailed_output; let enable_color = force_colors.unwrap_or_else(|| atty::is(atty::Stream::Stderr)); - let timer = fast_local_time::FastLocalTime { with_fractional: detailed_output }; + let timer: Box = if use_utc { + Box::new(ChronoUtc::with_format("%Y-%m-%dT%H:%M:%S%.6fZ".to_string())) + } else { + Box::new(FastLocalTime { with_fractional: detailed_output }) + }; let event_format = EventFormat { timer, @@ -203,6 +209,7 @@ pub struct LoggerBuilder { custom_profiler: Option>, log_reloading: bool, force_colors: Option, + use_utc: bool, detailed_output: bool, } @@ -215,6 +222,7 @@ impl LoggerBuilder { custom_profiler: None, log_reloading: false, force_colors: None, + use_utc: false, detailed_output: false, } } @@ -261,6 +269,12 @@ impl LoggerBuilder { self } + /// Use UTC in log output. + pub fn with_utc(&mut self, utc: bool) -> &mut Self { + self.use_utc = utc; + self + } + /// Initialize the global logger /// /// This sets various global logging and tracing instances and thus may only be called once. @@ -271,6 +285,7 @@ impl LoggerBuilder { &self.directives, Some(&profiling_targets), self.force_colors, + self.use_utc, self.detailed_output, |builder| enable_log_reloading!(builder), )?; @@ -289,6 +304,7 @@ impl LoggerBuilder { &self.directives, Some(&profiling_targets), self.force_colors, + self.use_utc, self.detailed_output, |builder| builder, )?; @@ -308,6 +324,7 @@ impl LoggerBuilder { &self.directives, None, self.force_colors, + self.use_utc, self.detailed_output, |builder| enable_log_reloading!(builder), )?; @@ -320,6 +337,7 @@ impl LoggerBuilder { &self.directives, None, self.force_colors, + self.use_utc, self.detailed_output, |builder| builder, )?; @@ -440,7 +458,7 @@ mod tests { let test_directives = "test-target=info"; let _guard = init_logger(&test_directives); - log::info!(target: "test-target", "{}", EXPECTED_LOG_MESSAGE); + info!(target: "test-target", "{}", EXPECTED_LOG_MESSAGE); } } @@ -475,7 +493,7 @@ mod tests { #[crate::logging::prefix_logs_with(EXPECTED_NODE_NAME)] fn prefix_in_log_lines_process() { - log::info!("{}", EXPECTED_LOG_MESSAGE); + info!("{}", EXPECTED_LOG_MESSAGE); } /// This is not an actual test, it is used by the `do_not_write_with_colors_on_tty` test.