Log using tracing (#16)

* Log using tracing

* Clippy

* Add missing file

Author: jfldde

Cargo.toml

@@ -13,13 +13,13 @@ bollard = { version = "0.17.1" }
 futures = "0.3"
 hex = { version = "0.4.3", default-features = false, features = ["serde"] }
 jsonrpsee = { version = "0.24.2", features = ["http-client", "ws-client"] }
-log = "0.4"
 rand = "0.8"
 serde = { version = "1.0.192", default-features = false, features = ["alloc", "derive"] }
 serde_json = { version = "1.0", default-features = false }
 tempfile = "3.8"
 tokio = { version = "1.39", features = ["full"] }
 toml = "0.8.0"
+tracing = { version = "0.1.40", default-features = false }
 
 # Citrea dependencies
 sov-ledger-rpc = { git = "https://github.com/chainwayxyz/citrea", rev = "82bf52d", default-features = false, features = ["client"] }

src/batch_prover.rs

@@ -1,8 +1,8 @@
 use std::time::SystemTime;
 
 use anyhow::bail;
-use log::debug;
 use tokio::time::{sleep, Duration};
+use tracing::debug;
 
 use super::{config::FullBatchProverConfig, Result};
 use crate::node::Node;

src/bitcoin.rs

@@ -11,6 +11,7 @@ use bitcoin::Address;
 use bitcoincore_rpc::{json::AddressType::Bech32m, Auth, Client, RpcApi};
 use futures::TryStreamExt;
 use tokio::{process::Command, sync::OnceCell, time::sleep};
+use tracing::{debug, info, trace};
 
 use super::{
     config::BitcoinConfig,
@@ -105,7 +106,7 @@ impl BitcoinNode {
 
         while start.elapsed() < timeout_duration {
             if !self.is_process_running().await? {
-                println!("Bitcoin daemon has stopped successfully");
+                info!("Bitcoin daemon has stopped successfully");
                 return Ok(());
             }
             sleep(Duration::from_millis(200)).await;
@@ -182,7 +183,7 @@ impl NodeT for BitcoinNode {
 
     fn spawn(config: &Self::Config) -> Result<SpawnOutput> {
         let args = config.args();
-        println!("Running bitcoind with args : {args:?}");
+        debug!("Running bitcoind with args : {args:?}");
 
         Command::new("bitcoind")
             .args(&args)
@@ -198,7 +199,7 @@ impl NodeT for BitcoinNode {
     }
 
     async fn wait_for_ready(&self, timeout: Option<Duration>) -> Result<()> {
-        println!("Waiting for ready");
+        trace!("Waiting for ready");
         let start = Instant::now();
         let timeout = timeout.unwrap_or(Duration::from_secs(30));
         while start.elapsed() < timeout {
@@ -210,7 +211,7 @@ impl NodeT for BitcoinNode {
             }
             tokio::time::sleep(Duration::from_millis(500)).await;
         }
-        anyhow::bail!("Node failed to become ready within the specified timeout")
+        bail!("Node failed to become ready within the specified timeout")
     }
 
     fn client(&self) -> &Self::Client {
@@ -249,7 +250,7 @@ impl Restart for BitcoinNode {
                     .try_collect::<Vec<_>>()
                     .await?;
                 env.docker.remove_container(&output.id, None).await?;
-                println!("Docker container {} succesfully removed", output.id);
+                info!("Docker container {} succesfully removed", output.id);
                 Ok(())
             }
         }
@@ -361,5 +362,5 @@ async fn wait_for_rpc_ready(client: &Client, timeout: Option<Duration>) -> Resul
             Err(_) => sleep(Duration::from_millis(500)).await,
         }
     }
-    Err(anyhow::anyhow!("Timeout waiting for RPC to be ready"))
+    bail!("Timeout waiting for RPC to be ready")
 }

src/citrea_config/mod.rs

@@ -21,8 +21,8 @@ pub fn from_toml_path<P: AsRef<std::path::Path>, R: serde::de::DeserializeOwned>
         let mut file = File::open(path)?;
         file.read_to_string(&mut contents)?;
     }
-    log::debug!("Config file size: {} bytes", contents.len());
-    log::trace!("Config file contents: {}", &contents);
+    tracing::debug!("Config file size: {} bytes", contents.len());
+    tracing::trace!("Config file contents: {}", &contents);
 
     let result: R = toml::from_str(&contents)?;
 

src/client.rs

@@ -6,12 +6,12 @@ use jsonrpsee::{
     http_client::{HttpClient, HttpClientBuilder},
     rpc_params,
 };
-use log::debug;
 use sov_ledger_rpc::client::RpcClient;
 use sov_rollup_interface::rpc::{
     SequencerCommitmentResponse, SoftConfirmationResponse, VerifiedProofResponse,
 };
 use tokio::time::sleep;
+use tracing::trace;
 
 pub struct Client {
     client: HttpClient,
@@ -97,7 +97,7 @@ impl Client {
         let start = SystemTime::now();
         let timeout = timeout.unwrap_or(Duration::from_secs(30)); // Default 30 seconds timeout
         loop {
-            debug!("Waiting for soft confirmation {}", num);
+            trace!("Waiting for soft confirmation {}", num);
             let latest_block = self.client.get_head_soft_confirmation_height().await?;
 
             if latest_block >= num {

src/docker.rs

@@ -17,6 +17,7 @@ use bollard::{
 };
 use futures::StreamExt;
 use tokio::{fs::File, io::AsyncWriteExt, task::JoinHandle};
+use tracing::{debug, info};
 
 use super::{config::DockerConfig, traits::SpawnOutput, utils::generate_test_id};
 use crate::traits::ContainerSpawnOutput;
@@ -91,7 +92,7 @@ impl DockerEnv {
     }
 
     pub async fn spawn(&self, config: DockerConfig) -> Result<SpawnOutput> {
-        println!("Spawning docker with config {config:#?}");
+        debug!("Spawning docker with config {config:#?}");
         let exposed_ports: HashMap<String, HashMap<(), ()>> = config
             .ports
             .iter()
@@ -146,9 +147,6 @@ impl DockerEnv {
             .context("Image not specified in config")?;
         self.ensure_image_exists(image).await?;
 
-        // println!("options :{options:?}");
-        // println!("config :{container_config:?}");
-
         let container = self
             .docker
             .create_container::<String, String>(None, container_config)
@@ -196,7 +194,7 @@ impl DockerEnv {
             return Ok(());
         }
 
-        println!("Pulling image: {image}");
+        info!("Pulling image: {image}...");
         let options = Some(CreateImageOptions {
             from_image: image,
             ..Default::default()
@@ -214,7 +212,7 @@ impl DockerEnv {
                 Err(e) => return Err(anyhow::anyhow!("Failed to pull image: {}", e)),
             }
         }
-        println!("Image succesfully pulled");
+        info!("Image succesfully pulled");
 
         Ok(())
     }

src/framework.rs

@@ -1,6 +1,7 @@
 use std::{future::Future, sync::Arc};
 
 use bitcoincore_rpc::RpcApi;
+use tracing::{debug, info};
 
 use super::{
     bitcoin::BitcoinNodeCluster,
@@ -119,13 +120,13 @@ impl TestFramework {
 
     pub fn show_log_paths(&self) {
         if self.show_logs {
-            println!(
+            info!(
                 "Logs available at {}",
                 self.ctx.config.test_case.dir.display()
             );
 
             for node in self.get_nodes_as_log_provider() {
-                println!(
+                info!(
                     "{} logs available at : {}",
                     node.kind(),
                     node.log_path().display()
@@ -135,14 +136,14 @@ impl TestFramework {
     }
 
     pub fn dump_log(&self) -> Result<()> {
-        println!("Dumping logs:");
+        debug!("Dumping logs:");
 
         let n_lines = std::env::var("TAIL_N_LINES")
             .ok()
             .and_then(|v| v.parse::<usize>().ok())
             .unwrap_or(25);
         for node in self.get_nodes_as_log_provider() {
-            println!("{} logs (last {n_lines} lines):", node.kind());
+            debug!("{} logs (last {n_lines} lines):", node.kind());
             if let Err(e) = tail_file(&node.log_path(), n_lines) {
                 eprint!("{e}");
             }
@@ -151,34 +152,34 @@ impl TestFramework {
     }
 
     pub async fn stop(&mut self) -> Result<()> {
-        println!("Stopping framework...");
+        info!("Stopping framework...");
 
         if let Some(sequencer) = &mut self.sequencer {
             let _ = sequencer.stop().await;
-            println!("Successfully stopped sequencer");
+            info!("Successfully stopped sequencer");
         }
 
         if let Some(batch_prover) = &mut self.batch_prover {
             let _ = batch_prover.stop().await;
-            println!("Successfully stopped batch_prover");
+            info!("Successfully stopped batch_prover");
         }
 
         if let Some(light_client_prover) = &mut self.light_client_prover {
             let _ = light_client_prover.stop().await;
-            println!("Successfully stopped light_client_prover");
+            info!("Successfully stopped light_client_prover");
         }
 
         if let Some(full_node) = &mut self.full_node {
             let _ = full_node.stop().await;
-            println!("Successfully stopped full_node");
+            info!("Successfully stopped full_node");
         }
 
         let _ = self.bitcoin_nodes.stop_all().await;
-        println!("Successfully stopped bitcoin nodes");
+        info!("Successfully stopped bitcoin nodes");
 
         if let Some(docker) = self.ctx.docker.as_ref() {
             let _ = docker.cleanup().await;
-            println!("Successfully cleaned docker");
+            info!("Successfully cleaned docker");
         }
 
         Ok(())

src/light_client_prover.rs

@@ -1,8 +1,8 @@
 use std::time::SystemTime;
 
 use anyhow::bail;
-use log::debug;
 use tokio::time::{sleep, Duration};
+use tracing::debug;
 
 use super::{config::FullLightClientProverConfig, Result};
 use crate::node::Node;

src/node.rs

@@ -8,12 +8,12 @@ use std::{
 
 use anyhow::{bail, Context};
 use async_trait::async_trait;
-use log::debug;
 use serde::Serialize;
 use tokio::{
     process::Command,
     time::{sleep, Instant},
 };
+use tracing::trace;
 
 use crate::{
     client::Client,
@@ -130,7 +130,7 @@ impl<C: Config> Node<C> {
         let start = SystemTime::now();
         let timeout = timeout.unwrap_or(Duration::from_secs(30)); // Default 30 seconds timeout
         loop {
-            debug!("Waiting for soft confirmation {}", num);
+            trace!("Waiting for soft confirmation {}", num);
             let latest_block = self
                 .client
                 .ledger_get_head_soft_confirmation_height()

src/traits.rs

@@ -4,6 +4,7 @@ use anyhow::Context;
 use async_trait::async_trait;
 use bollard::{container::StopContainerOptions, Docker};
 use tokio::process::Child;
+use tracing::info;
 
 use super::Result;
 use crate::node::NodeKind;
@@ -45,7 +46,7 @@ pub trait NodeT: Send {
                 Ok(())
             }
             SpawnOutput::Container(ContainerSpawnOutput { id, .. }) => {
-                println!("Stopping container {id}");
+                info!("Stopping container {id}");
                 let docker =
                     Docker::connect_with_local_defaults().context("Failed to connect to Docker")?;
                 docker