Make tracing::log work in the runtime (#4863)

Co-authored-by: command-bot <>
paritytech · Jul 8, 2024 · 7290042 · 7290042
1 parent 8af45d2
commit 7290042
Show file tree

Hide file tree

Showing 6 changed files with 27 additions and 8 deletions.
diff --git a/Cargo.lock b/Cargo.lock
diff --git a/prdoc/pr_4863.prdoc b/prdoc/pr_4863.prdoc
@@ -0,0 +1,10 @@
+title: "Make `tracing::log` work in the runtime"
+
+doc:
+  - audience: Runtime Dev
+    description: |
+      Make `tracing::log` work in the runtime as `log` works in the runtime.
+
+crates:
+  - name: sp-runtime
+    bump: patch
diff --git a/substrate/primitives/runtime/Cargo.toml b/substrate/primitives/runtime/Cargo.toml
@@ -34,6 +34,7 @@ sp-io = { workspace = true }
 sp-std = { workspace = true }
 sp-weights = { workspace = true }
 docify = { workspace = true }
+tracing = { workspace = true, features = ["log"], default-features = false }
 
 simple-mermaid = { version = "0.1.1", optional = true }
 
@@ -69,6 +70,7 @@ std = [
 	"sp-std/std",
 	"sp-tracing/std",
 	"sp-weights/std",
+	"tracing/std",
 ]
 
 # Serde support without relying on std features.

diff --git a/substrate/primitives/runtime/src/runtime_logger.rs b/substrate/primitives/runtime/src/runtime_logger.rs
@@ -66,34 +66,35 @@ impl log::Log for RuntimeLogger {
 #[cfg(test)]
 mod tests {
 	use sp_api::ProvideRuntimeApi;
-	use std::{env, str::FromStr};
+	use std::env;
 	use substrate_test_runtime_client::{
 		runtime::TestAPI, DefaultTestClientBuilderExt, TestClientBuilder, TestClientBuilderExt,
 	};
 
 	#[test]
-	fn ensure_runtime_logger_respects_host_max_log_level() {
+	fn ensure_runtime_logger_works() {
 		if env::var("RUN_TEST").is_ok() {
 			sp_tracing::try_init_simple();
-			log::set_max_level(log::LevelFilter::from_str(&env::var("RUST_LOG").unwrap()).unwrap());
 
 			let client = TestClientBuilder::new().build();
 			let runtime_api = client.runtime_api();
 			runtime_api
 				.do_trace_log(client.chain_info().genesis_hash)
 				.expect("Logging should not fail");
 		} else {
-			for (level, should_print) in &[("trace", true), ("info", false)] {
+			for (level, should_print) in &[("test=trace", true), ("info", false)] {
 				let executable = std::env::current_exe().unwrap();
 				let output = std::process::Command::new(executable)
 					.env("RUN_TEST", "1")
 					.env("RUST_LOG", level)
-					.args(&["--nocapture", "ensure_runtime_logger_respects_host_max_log_level"])
+					.args(&["--nocapture", "ensure_runtime_logger_works"])
 					.output()
 					.unwrap();
 
 				let output = String::from_utf8(output.stderr).unwrap();
 				assert!(output.contains("Hey I'm runtime") == *should_print);
+				assert!(output.contains("THIS IS TRACING") == *should_print);
+				assert!(output.contains("Hey, I'm tracing") == *should_print);
 			}
 		}
 	}

diff --git a/substrate/test-utils/runtime/Cargo.toml b/substrate/test-utils/runtime/Cargo.toml
@@ -53,7 +53,7 @@ sp-externalities = { workspace = true }
 array-bytes = { optional = true, workspace = true, default-features = true }
 serde_json = { workspace = true, features = ["alloc"] }
 log = { workspace = true }
-hex-literal = { workspace = true, default-features = true }
+tracing = { workspace = true, default-features = false }
 
 [dev-dependencies]
 futures = { workspace = true }
@@ -112,6 +112,7 @@ std = [
 	"sp-trie/std",
 	"sp-version/std",
 	"substrate-wasm-builder",
+	"tracing/std",
 	"trie-db/std",
 ]
 

diff --git a/substrate/test-utils/runtime/src/lib.rs b/substrate/test-utils/runtime/src/lib.rs
@@ -596,7 +596,11 @@ impl_runtime_apis! {
 		}
 
 		fn do_trace_log() {
-			log::trace!("Hey I'm runtime");
+			log::trace!(target: "test", "Hey I'm runtime");
+
+			let data = "THIS IS TRACING";
+
+			tracing::trace!(target: "test", %data, "Hey, I'm tracing");
 		}
 
 		fn verify_ed25519(sig: ed25519::Signature, public: ed25519::Public, message: Vec<u8>) -> bool {