Replace log/env_logger with tracing/tracing_subscriber (#689)

* Replace log/env_logger with tracing/tracing_subscriber

* Fix tests

* Cargo.lock

Cargo.toml

@@ -24,10 +24,10 @@ include = [
 ]
 
 [dependencies]
-env_logger = "0.9.0"
 anyhow = "1.0.61"
 clap = { version = "3.2.16", features = ["derive", "env"] }
-log = "0.4.17"
+tracing = "0.1.36"
+tracing-subscriber = "0.3.15"
 heck = "0.4.0"
 zip = { version = "0.6.2", default-features = false }
 parity-wasm = "0.45.0"

src/cmd/build.rs

@@ -340,7 +340,7 @@ fn exec_cargo_dylint(crate_metadata: &CrateMetadata, verbosity: Verbosity) -> Re
     let tmp_dir = tempfile::Builder::new()
         .prefix("cargo-contract-dylint_")
         .tempdir()?;
-    log::debug!("Using temp workspace at '{}'", tmp_dir.path().display());
+    tracing::debug!("Using temp workspace at '{}'", tmp_dir.path().display());
 
     let driver = include_bytes!(concat!(env!("OUT_DIR"), "/ink-dylint-driver.zip"));
     crate::util::unzip(driver, tmp_dir.path().to_path_buf(), None)?;
@@ -412,13 +412,13 @@ fn check_dylint_requirements(_working_dir: Option<&Path>) -> Result<()> {
             .stderr(std::process::Stdio::null())
             .spawn()
             .map_err(|err| {
-                log::debug!("Error spawning `{:?}`", cmd);
+                tracing::debug!("Error spawning `{:?}`", cmd);
                 err
             })?
             .wait()
             .map(|res| res.success())
             .map_err(|err| {
-                log::debug!("Error waiting for `{:?}`: {:?}", cmd, err);
+                tracing::debug!("Error waiting for `{:?}`: {:?}", cmd, err);
                 err
             })
     };
@@ -610,11 +610,11 @@ fn do_optimization(
         .as_ref()
         .expect("we just checked if `which` returned an err; qed")
         .as_path();
-    log::info!("Path to wasm-opt executable: {}", wasm_opt_path.display());
+    tracing::info!("Path to wasm-opt executable: {}", wasm_opt_path.display());
 
     check_wasm_opt_version_compatibility(wasm_opt_path)?;
 
-    log::info!(
+    tracing::info!(
         "Optimization level passed to wasm-opt: {}",
         optimization_level
     );
@@ -631,7 +631,7 @@ fn do_optimization(
     if keep_debug_symbols {
         command.arg("-g");
     }
-    log::info!("Invoking wasm-opt with {:?}", command);
+    tracing::info!("Invoking wasm-opt with {:?}", command);
     let output = command.output().map_err(|err| {
         anyhow::anyhow!(
             "Executing {} failed with {:?}",
@@ -727,7 +727,7 @@ fn check_wasm_opt_version_compatibility(wasm_opt_path: &Path) -> Result<()> {
             )
         })?;
 
-    log::info!(
+    tracing::info!(
         "The wasm-opt version output is '{}', which was parsed to '{}'",
         version_stdout,
         version_number
@@ -775,7 +775,7 @@ fn assert_compatible_ink_dependencies(
 ///
 /// This feature was introduced in `3.0.0-rc4` with `ink_env/ink-debug`.
 pub fn assert_debug_mode_supported(ink_version: &Version) -> anyhow::Result<()> {
-    log::info!("Contract version: {:?}", ink_version);
+    tracing::info!("Contract version: {:?}", ink_version);
     let minimum_version = Version::parse("3.0.0-rc4").expect("parsing version failed");
     if ink_version < &minimum_version {
         anyhow::bail!(

src/cmd/extrinsics/call.rs

@@ -91,7 +91,7 @@ impl CallCommand {
             load_metadata(self.extrinsic_opts.manifest_path.as_ref())?;
         let transcoder = ContractMessageTranscoder::new(&contract_metadata);
         let call_data = transcoder.encode(&self.message, &self.args)?;
-        log::debug!("Message data: {:?}", hex::encode(&call_data));
+        tracing::debug!("Message data: {:?}", hex::encode(&call_data));
 
         let signer = super::pair_signer(self.extrinsic_opts.signer()?);
 
@@ -168,7 +168,7 @@ impl CallCommand {
         signer: &PairSigner,
         transcoder: &ContractMessageTranscoder<'_>,
     ) -> Result<()> {
-        log::debug!("calling contract {:?}", self.contract);
+        tracing::debug!("calling contract {:?}", self.contract);
 
         let gas_limit = self
             .pre_submit_dry_run_gas_estimate(client, data.clone(), signer)

src/cmd/extrinsics/events.rs

@@ -61,7 +61,7 @@ pub fn display_events(
 
     for event in result.iter() {
         let event = event?;
-        log::debug!("displaying event {:?}", event);
+        tracing::debug!("displaying event {:?}", event);
 
         let event_metadata =
             subxt_metadata.event(event.pallet_index(), event.variant_index())?;
@@ -82,7 +82,7 @@ pub fn display_events(
                 event.variant_name(),
             ) && field.as_ref() == Some(&"data".to_string())
             {
-                log::debug!("event data: {:?}", hex::encode(&event_data));
+                tracing::debug!("event data: {:?}", hex::encode(&event_data));
                 let contract_event = transcoder.decode_contract_event(event_data)?;
                 maybe_println!(
                     verbosity,

src/cmd/extrinsics/instantiate.rs

@@ -142,7 +142,7 @@ impl InstantiateCommand {
         let verbosity = self.extrinsic_opts.verbosity()?;
 
         fn load_code(wasm_path: &Path) -> Result<Code> {
-            log::info!("Contract code path: {}", wasm_path.display());
+            tracing::info!("Contract code path: {}", wasm_path.display());
             let code = fs::read(&wasm_path)
                 .context(format!("Failed to read from {}", wasm_path.display()))?;
             Ok(Code::Upload(code.into()))
@@ -214,7 +214,7 @@ pub struct Exec<'a> {
 
 impl<'a> Exec<'a> {
     async fn exec(&self, code: Code, dry_run: bool) -> Result<()> {
-        log::debug!("instantiate data {:?}", self.args.data);
+        tracing::debug!("instantiate data {:?}", self.args.data);
         if dry_run {
             let result = self.instantiate_dry_run(code).await?;
             match result.result {

src/cmd/extrinsics/integration_tests.rs

@@ -71,7 +71,7 @@ impl ContractsNodeProcess {
         let mut attempts = 1;
         let client = loop {
             thread::sleep(time::Duration::from_secs(1));
-            log::info!(
+            tracing::info!(
                 "Connecting to contracts enabled node, attempt {}/{}",
                 attempts,
                 MAX_ATTEMPTS
@@ -102,17 +102,17 @@ impl ContractsNodeProcess {
                     attempts,
                     err
                 );
-                log::error!("{}", err);
+                tracing::error!("{}", err);
                 proc.kill()?;
                 Err(err)
             }
         }
     }
 
     fn kill(&mut self) {
-        log::info!("Killing contracts node process {}", self.proc.id());
+        tracing::info!("Killing contracts node process {}", self.proc.id());
         if let Err(err) = self.proc.kill() {
-            log::error!(
+            tracing::error!(
                 "Error killing contracts node process {}: {}",
                 self.proc.id(),
                 err
@@ -136,7 +136,7 @@ impl ContractsNodeProcess {
 #[ignore]
 #[async_std::test]
 async fn build_upload_instantiate_call() {
-    env_logger::try_init().ok();
+    tracing_subscriber::fmt::init();
 
     let tmp_dir = tempfile::Builder::new()
         .prefix("cargo-contract.cli.test.")
@@ -148,7 +148,7 @@ async fn build_upload_instantiate_call() {
         .await
         .expect("Error spawning contracts node");
 
-    log::info!(
+    tracing::info!(
         "Creating new contract in temporary directory {}",
         tmp_dir.path().to_string_lossy()
     );
@@ -164,13 +164,13 @@ async fn build_upload_instantiate_call() {
     let mut project_path = tmp_dir.path().to_path_buf();
     project_path.push("flipper");
 
-    log::info!("Building contract in {}", project_path.to_string_lossy());
+    tracing::info!("Building contract in {}", project_path.to_string_lossy());
     cargo_contract(project_path.as_path())
         .arg("build")
         .assert()
         .success();
 
-    log::info!("Uploading the code to the substrate-contracts-node chain");
+    tracing::info!("Uploading the code to the substrate-contracts-node chain");
     let output = cargo_contract(project_path.as_path())
         .arg("upload")
         .args(&["--suri", "//Alice"])
@@ -187,7 +187,7 @@ async fn build_upload_instantiate_call() {
     let code_hash = caps.get(1).unwrap().as_str();
     assert_eq!(64, code_hash.len());
 
-    log::info!("Instantiating the contract with code hash `{}`", code_hash);
+    tracing::info!("Instantiating the contract with code hash `{}`", code_hash);
     let output = cargo_contract(project_path.as_path())
         .arg("instantiate")
         .args(&["--constructor", "new"])
@@ -222,7 +222,7 @@ async fn build_upload_instantiate_call() {
     // call the `get` message via rpc to assert that it was set to the initial value
     call_get_rpc(true);
 
-    log::info!("Calling flip on the contract `{}`", contract_account);
+    tracing::info!("Calling flip on the contract `{}`", contract_account);
     cargo_contract(project_path.as_path())
         .arg("call")
         .args(&["--message", "flip"])

src/cmd/extrinsics/upload.rs

@@ -77,7 +77,7 @@ impl UploadCommand {
             None => crate_metadata.dest_wasm,
         };
 
-        log::info!("Contract code path: {}", wasm_path.display());
+        tracing::info!("Contract code path: {}", wasm_path.display());
         let code = std::fs::read(&wasm_path)
             .context(format!("Failed to read from {}", wasm_path.display()))?;
 

src/cmd/metadata.rs

@@ -330,7 +330,7 @@ mod tests {
 
     #[test]
     fn generate_metadata() {
-        env_logger::try_init().ok();
+        tracing_subscriber::fmt::init();
         with_new_contract_project(|manifest_path| {
             // add optional metadata fields
             let mut test_manifest = TestContractManifest::new(manifest_path)?;

src/crate_metadata.rs

@@ -135,7 +135,7 @@ impl CrateMetadata {
 
 /// Get the result of `cargo metadata`, together with the root package id.
 fn get_cargo_metadata(manifest_path: &ManifestPath) -> Result<(CargoMetadata, Package)> {
-    log::info!(
+    tracing::info!(
         "Fetching cargo metadata for {}",
         manifest_path.as_ref().to_string_lossy()
     );

src/main.rs

@@ -473,7 +473,7 @@ enum Command {
 }
 
 fn main() {
-    env_logger::init();
+    tracing_subscriber::fmt::init();
 
     let Opts::Contract(args) = Opts::parse();
     match exec(args.cmd) {

src/util.rs

@@ -89,7 +89,7 @@ where
     });
 
     if let Some(path) = working_dir {
-        log::debug!("Setting cargo working dir to '{}'", path.as_ref().display());
+        tracing::debug!("Setting cargo working dir to '{}'", path.as_ref().display());
         cmd.current_dir(path);
     }
 
@@ -107,7 +107,7 @@ where
         Verbosity::Default => &mut cmd,
     };
 
-    log::info!("Invoking cargo: {:?}", cmd);
+    tracing::info!("Invoking cargo: {:?}", cmd);
 
     let child = cmd
         // capture the stdout to return from this function as bytes