From d1f9fe0a994febff13f21b0edd223e838754e2fc Mon Sep 17 00:00:00 2001 From: Alexandru Vasile <60601340+lexnv@users.noreply.github.com> Date: Mon, 15 Apr 2024 17:33:55 +0300 Subject: [PATCH] logging(fix): Use the proper log target for logging (#4124) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This PR ensures the proper logging target (ie `libp2p_tcp` or `beefy`) is displayed. The issue has been introduced in: https://github.com/paritytech/polkadot-sdk/pull/4059, which removes the normalized metadata of logs. From [documentation](https://docs.rs/tracing-log/latest/tracing_log/trait.NormalizeEvent.html#tymethod.normalized_metadata): > In tracing-log, an Event produced by a log (through [AsTrace](https://docs.rs/tracing-log/latest/tracing_log/trait.AsTrace.html)) has an hard coded “log” target > [normalized_metadata](https://docs.rs/tracing-log/latest/tracing_log/trait.NormalizeEvent.html#tymethod.normalized_metadata): If this Event comes from a log, this method provides a new normalized Metadata which has all available attributes from the original log, including file, line, module_path and target This has low implications if a version was deployed containing the mentioned pull request, as we'll lose the ability to distinguish between log targets. ### Before this PR ``` 2024-04-15 12:45:40.327 INFO main log: Parity Polkadot 2024-04-15 12:45:40.328 INFO main log: ✌️ version 1.10.0-d1b0ef76a8b 2024-04-15 12:45:40.328 INFO main log: ❤️ by Parity Technologies , 2017-2024 2024-04-15 12:45:40.328 INFO main log: 📋 Chain specification: Development 2024-04-15 12:45:40.328 INFO main log: 🏷 Node name: yellow-eyes-2963 2024-04-15 12:45:40.328 INFO main log: 👤 Role: AUTHORITY 2024-04-15 12:45:40.328 INFO main log: 💾 Database: RocksDb at /tmp/substrated39i9J/chains/rococo_dev/db/full 2024-04-15 12:45:44.508 WARN main log: Took active validators from set with wrong size ... 2024-04-15 12:45:45.805 INFO main log: 👶 Starting BABE Authorship worker 2024-04-15 12:45:45.806 INFO tokio-runtime-worker log: 🥩 BEEFY gadget waiting for BEEFY pallet to become available... 2024-04-15 12:45:45.806 DEBUG tokio-runtime-worker log: New listen address: /ip6/::1/tcp/30333 2024-04-15 12:45:45.806 DEBUG tokio-runtime-worker log: New listen address: /ip4/127.0.0.1/tcp/30333 ``` ### After this PR ``` 2024-04-15 12:59:45.623 INFO main sc_cli::runner: Parity Polkadot 2024-04-15 12:59:45.623 INFO main sc_cli::runner: ✌️ version 1.10.0-d1b0ef76a8b 2024-04-15 12:59:45.623 INFO main sc_cli::runner: ❤️ by Parity Technologies , 2017-2024 2024-04-15 12:59:45.623 INFO main sc_cli::runner: 📋 Chain specification: Development 2024-04-15 12:59:45.623 INFO main sc_cli::runner: 🏷 Node name: helpless-lizards-0550 2024-04-15 12:59:45.623 INFO main sc_cli::runner: 👤 Role: AUTHORITY ... 2024-04-15 12:59:50.204 INFO tokio-runtime-worker beefy: 🥩 BEEFY gadget waiting for BEEFY pallet to become available... 2024-04-15 12:59:50.204 DEBUG tokio-runtime-worker libp2p_tcp: New listen address: /ip6/::1/tcp/30333 2024-04-15 12:59:50.204 DEBUG tokio-runtime-worker libp2p_tcp: New listen address: /ip4/127.0.0.1/tcp/30333 ``` Signed-off-by: Alexandru Vasile --- substrate/client/tracing/src/logging/event_format.rs | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/substrate/client/tracing/src/logging/event_format.rs b/substrate/client/tracing/src/logging/event_format.rs index 9589c1dfee..8d87542784 100644 --- a/substrate/client/tracing/src/logging/event_format.rs +++ b/substrate/client/tracing/src/logging/event_format.rs @@ -21,6 +21,7 @@ use ansi_term::Colour; use regex::Regex; use std::fmt::{self, Write}; use tracing::{Event, Level, Subscriber}; +use tracing_log::NormalizeEvent; use tracing_subscriber::{ fmt::{format, time::FormatTime, FmtContext, FormatEvent, FormatFields}, registry::LookupSpan, @@ -60,10 +61,12 @@ where N: for<'a> FormatFields<'a> + 'static, { let mut 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, &mut format::Writer::new(&mut writer), self.enable_color)?; if self.display_level { - let fmt_level = FmtLevel::new(event.metadata().level(), self.enable_color); + let fmt_level = FmtLevel::new(meta.level(), self.enable_color); write!(writer, "{} ", fmt_level)?; } @@ -81,7 +84,7 @@ where } if self.display_target { - write!(writer, "{}: ", event.metadata().target())?; + write!(writer, "{}: ", meta.target())?; } // Custom code to display node name