diff --git a/substrate/Cargo.lock b/substrate/Cargo.lock index e04aec94d7..992a49306f 100644 --- a/substrate/Cargo.lock +++ b/substrate/Cargo.lock @@ -8253,7 +8253,6 @@ dependencies = [ "hex-literal", "lazy_static", "libsecp256k1", - "log 0.4.14", "lru 0.6.6", "parity-scale-codec", "parking_lot 0.11.2", diff --git a/substrate/client/executor/Cargo.toml b/substrate/client/executor/Cargo.toml index 0d0f2a8bd9..47ef050050 100644 --- a/substrate/client/executor/Cargo.toml +++ b/substrate/client/executor/Cargo.toml @@ -31,10 +31,10 @@ sc-executor-common = { version = "0.10.0-dev", path = "common" } sc-executor-wasmi = { version = "0.10.0-dev", path = "wasmi" } sc-executor-wasmtime = { version = "0.10.0-dev", path = "wasmtime", optional = true } parking_lot = "0.11.2" -log = "0.4.8" libsecp256k1 = "0.7" sp-core-hashing-proc-macro = { version = "4.0.0-dev", path = "../../primitives/core/hashing/proc-macro" } lru = "0.6.6" +tracing = "0.1.29" [dev-dependencies] wat = "1.0" @@ -45,7 +45,6 @@ sp-state-machine = { version = "0.11.0", path = "../../primitives/state-machine" sp-runtime = { version = "5.0.0", path = "../../primitives/runtime" } sp-maybe-compressed-blob = { version = "4.1.0-dev", path = "../../primitives/maybe-compressed-blob" } sc-tracing = { version = "4.0.0-dev", path = "../tracing" } -tracing = "0.1.29" tracing-subscriber = "0.2.19" paste = "1.0" regex = "1" diff --git a/substrate/client/executor/src/native_executor.rs b/substrate/client/executor/src/native_executor.rs index 1bc87840ba..363ea474a7 100644 --- a/substrate/client/executor/src/native_executor.rs +++ b/substrate/client/executor/src/native_executor.rs @@ -35,7 +35,6 @@ use std::{ }; use codec::{Decode, Encode}; -use log::trace; use sc_executor_common::{ runtime_blob::RuntimeBlob, wasm_runtime::{InvokeMethod, WasmInstance, WasmModule}, @@ -301,6 +300,12 @@ where _use_native: bool, _native_call: Option, ) -> (Result>, bool) { + tracing::trace!( + target: "executor", + %method, + "Executing function", + ); + let result = self.with_instance( runtime_code, ext, @@ -422,10 +427,10 @@ impl RuntimeSpawn for RuntimeInstanceSpawn { let async_ext = match new_async_externalities(scheduler.clone()) { Ok(val) => val, Err(e) => { - log::error!( + tracing::error!( target: "executor", - "Failed to setup externalities for async context: {}", - e, + error = %e, + "Failed to setup externalities for async context.", ); // This will drop sender and receiver end will panic @@ -438,10 +443,10 @@ impl RuntimeSpawn for RuntimeInstanceSpawn { )) { Ok(val) => val, Err(e) => { - log::error!( + tracing::error!( target: "executor", - "Failed to setup runtime extension for async externalities: {}", - e, + error = %e, + "Failed to setup runtime extension for async externalities", ); // This will drop sender and receiver end will panic @@ -476,7 +481,7 @@ impl RuntimeSpawn for RuntimeInstanceSpawn { Err(error) => { // If execution is panicked, the `join` in the original runtime code will // panic as well, since the sender is dropped without sending anything. - log::error!("Call error in spawned task: {}", error); + tracing::error!(error = %error, "Call error in spawned task"); }, } }), @@ -518,10 +523,10 @@ fn preregister_builtin_ext(module: Arc) { RuntimeInstanceSpawn::with_externalities_and_module(module, ext) { if let Err(e) = ext.register_extension(RuntimeSpawnExt(Box::new(runtime_spawn))) { - trace!( + tracing::trace!( target: "executor", - "Failed to register `RuntimeSpawnExt` instance on externalities: {:?}", - e, + error = ?e, + "Failed to register `RuntimeSpawnExt` instance on externalities", ) } } @@ -543,6 +548,12 @@ impl CodeExecutor for NativeElseWasmExecut use_native: bool, native_call: Option, ) -> (Result>, bool) { + tracing::trace!( + target: "executor", + function = %method, + "Executing function", + ); + let mut used_native = false; let result = self.wasm.with_instance( runtime_code, @@ -558,11 +569,11 @@ impl CodeExecutor for NativeElseWasmExecut match (use_native, can_call_with, native_call) { (_, false, _) | (false, _, _) => { if !can_call_with { - trace!( + tracing::trace!( target: "executor", - "Request for native execution failed (native: {}, chain: {})", - self.native_version.runtime_version, - onchain_version, + native = %self.native_version.runtime_version, + chain = %onchain_version, + "Request for native execution failed", ); } @@ -572,12 +583,11 @@ impl CodeExecutor for NativeElseWasmExecut }) }, (true, true, Some(call)) => { - trace!( + tracing::trace!( target: "executor", - "Request for native execution with native call succeeded \ - (native: {}, chain: {}).", - self.native_version.runtime_version, - onchain_version, + native = %self.native_version.runtime_version, + chain = %onchain_version, + "Request for native execution with native call succeeded" ); used_native = true; @@ -587,11 +597,11 @@ impl CodeExecutor for NativeElseWasmExecut Ok(res) }, _ => { - trace!( + tracing::trace!( target: "executor", - "Request for native execution succeeded (native: {}, chain: {})", - self.native_version.runtime_version, - onchain_version + native = %self.native_version.runtime_version, + chain = %onchain_version, + "Request for native execution succeeded", ); used_native = true; diff --git a/substrate/client/executor/src/wasm_runtime.rs b/substrate/client/executor/src/wasm_runtime.rs index 2cccb6f9c3..d996d7b490 100644 --- a/substrate/client/executor/src/wasm_runtime.rs +++ b/substrate/client/executor/src/wasm_runtime.rs @@ -103,23 +103,23 @@ impl VersionedRuntime { let result = f(&self.module, &mut *instance, self.version.as_ref(), ext); if let Err(e) = &result { if new_inst { - log::warn!( + tracing::warn!( target: "wasm-runtime", - "Fresh runtime instance failed with {}", - e, + error = %e, + "Fresh runtime instance failed", ) } else { - log::warn!( + tracing::warn!( target: "wasm-runtime", - "Evicting failed runtime instance: {}", - e, + error = %e, + "Evicting failed runtime instance", ); } } else { *locked = Some(instance); if new_inst { - log::debug!( + tracing::debug!( target: "wasm-runtime", "Allocated WASM instance {}/{}", index + 1, @@ -131,7 +131,7 @@ impl VersionedRuntime { result }, None => { - log::warn!(target: "wasm-runtime", "Ran out of free WASM instances"); + tracing::warn!(target: "wasm-runtime", "Ran out of free WASM instances"); // Allocate a new instance let mut instance = self.module.new_instance()?; @@ -259,7 +259,7 @@ impl RuntimeCache { match result { Ok(ref result) => { - log::debug!( + tracing::debug!( target: "wasm-runtime", "Prepared new runtime version {:?} in {} ms.", result.version, @@ -267,7 +267,7 @@ impl RuntimeCache { ); }, Err(ref err) => { - log::warn!(target: "wasm-runtime", "Cannot create a runtime: {:?}", err); + tracing::warn!(target: "wasm-runtime", error = ?err, "Cannot create a runtime"); }, }