From 7290042ad4975e9d42633f228e331f286397025e Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Bastian=20K=C3=B6cher?= <git@kchr.de>
Date: Mon, 8 Jul 2024 16:19:25 +0200
Subject: [PATCH] Make `tracing::log` work in the runtime (#4863)

Co-authored-by: command-bot <>
---
 Cargo.lock                                         |  3 ++-
 prdoc/pr_4863.prdoc                                | 10 ++++++++++
 substrate/primitives/runtime/Cargo.toml            |  2 ++
 substrate/primitives/runtime/src/runtime_logger.rs | 11 ++++++-----
 substrate/test-utils/runtime/Cargo.toml            |  3 ++-
 substrate/test-utils/runtime/src/lib.rs            |  6 +++++-
 6 files changed, 27 insertions(+), 8 deletions(-)
 create mode 100644 prdoc/pr_4863.prdoc

diff --git a/Cargo.lock b/Cargo.lock
index 046f9a15bbd..df96a2140ab 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -20511,6 +20511,7 @@ dependencies = [
  "sp-tracing 16.0.0",
  "sp-weights",
  "substrate-test-runtime-client",
+ "tracing",
  "zstd 0.12.4",
 ]
 
@@ -21487,7 +21488,6 @@ dependencies = [
  "frame-system",
  "frame-system-rpc-runtime-api",
  "futures",
- "hex-literal",
  "log",
  "pallet-babe",
  "pallet-balances",
@@ -21525,6 +21525,7 @@ dependencies = [
  "sp-version",
  "substrate-test-runtime-client",
  "substrate-wasm-builder",
+ "tracing",
  "trie-db",
 ]
 
diff --git a/prdoc/pr_4863.prdoc b/prdoc/pr_4863.prdoc
new file mode 100644
index 00000000000..eb43b67a45c
--- /dev/null
+++ 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
index 4fafe45ff28..83b9422ca1d 100644
--- 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
index b7374b8b6f6..6f1e738eb0e 100644
--- a/substrate/primitives/runtime/src/runtime_logger.rs
+++ b/substrate/primitives/runtime/src/runtime_logger.rs
@@ -66,16 +66,15 @@ 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();
@@ -83,17 +82,19 @@ mod tests {
 				.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
index e3282f8e598..5c8f49a6db8 100644
--- 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
index a5769b56dd5..a13441302e4 100644
--- 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 {
-- 
GitLab