refactor: Switch logging from log + env_logger to tracing + tracing_s…

…ubscriber This switches the code base to [tokio/tracing](https://github.com/tokio-rs/tracing). 1. tracing's notion of Spans allows us to instrument logs with context that lets us make sense of the application's state, even in a concurrent of distributed context. The [announcement on the tokio blog](https://tokio.rs/blog/2019-08-tracing) is a pretty compact intro to the gist of it. 2. This gives us access to the tracing ecosystem, see MystenLabs/narwhal#26 for more details This PR transforms the "rails" of logging from using log + event_logger to using tracing, and thereby opens the ability to open Spans or use the `#[instrument]` macro. It keeps full backward-compatibility with the prior logs. It may mess up the fabric benchmarking files, which I'm no longer sure we maintain. If it does, it would be because of different time printing formats, in particular it's a bit difficult to make tracing produce the wonky timestamps of log. As a consequence the python scripts may need massaging to handle RFC 3339 instead of ISO8601.
MystenLabs · huitseeker · Jan 29, 2022 · Jan 28, 2022 · Jan 29, 2022 · fc6d3463173bc5b5c680f4200131ee52eaa5a1c3
commit fc6d3463173bc5b5c680f4200131ee52eaa5a1c3
diff --git a/fastpay/Cargo.toml b/fastpay/Cargo.toml
@@ -10,9 +10,7 @@ edition = "2021"
 anyhow = "1.0.53"
 bytes = "1.1.0"
 clap = "3.0.13"
-env_logger = "0.9.0"
 futures = "0.3.19"
-log = "0.4.14"
 net2 = "0.2.37"
 serde = { version = "1.0.136", features = ["derive"] }
 serde_json = "1.0.78"
@@ -30,6 +28,8 @@ rocksdb = "0.17.0"
 hex = "0.4.3"
 async-trait = "0.1.52"
 serde_with = "1.11.0"
+tracing = { version = "0.1", features = ["log"] }
+tracing-subscriber = { version = "0.3", features = ["time", "env-filter"] }
 
 bcs = "0.1.3"
 fastpay_core = { path = "../fastpay_core" }

diff --git a/fastpay/src/bench.rs b/fastpay/src/bench.rs
@@ -9,14 +9,16 @@ use fastpay_core::authority::*;
 use fastx_types::FASTX_FRAMEWORK_ADDRESS;
 use fastx_types::{base_types::*, committee::*, messages::*, object::Object, serialize::*};
 use futures::stream::StreamExt;
-use log::*;
 use move_core_types::ident_str;
 use rand::rngs::StdRng;
 use rand::Rng;
 use std::time::{Duration, Instant};
 use structopt::StructOpt;
 use tokio::runtime::Runtime;
 use tokio::{runtime::Builder, time};
+use tracing::subscriber::set_global_default;
+use tracing::*;
+use tracing_subscriber::EnvFilter;
 
 use rocksdb::Options;
 use std::env;
@@ -84,7 +86,11 @@ impl std::fmt::Display for BenchmarkType {
     }
 }
 fn main() {
-    env_logger::Builder::from_env(env_logger::Env::default().default_filter_or("info")).init();
+    let env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info"));
+    let subscriber_builder =
+        tracing_subscriber::fmt::Subscriber::builder().with_env_filter(env_filter);
+    let subscriber = subscriber_builder.with_writer(std::io::stderr).finish();
+    set_global_default(subscriber).expect("Failed to set subscriber");
     let benchmark = ClientServerBenchmark::from_args();
     let (state, orders) = benchmark.make_structures();
 

diff --git a/fastpay/src/client.rs b/fastpay/src/client.rs
@@ -11,13 +11,14 @@ use move_core_types::transaction_argument::convert_txn_args;
 use bytes::Bytes;
 use fastx_types::object::Object;
 use futures::stream::StreamExt;
-use log::*;
 use std::{
     collections::{HashMap, HashSet},
     time::{Duration, Instant},
 };
 use structopt::StructOpt;
 use tokio::runtime::Runtime;
+use tracing::{subscriber::set_global_default, *};
+use tracing_subscriber::EnvFilter;
 
 fn make_authority_clients(
     committee_config: &CommitteeConfig,
@@ -459,7 +460,12 @@ enum ClientCommands {
 }
 
 fn main() {
-    env_logger::Builder::from_env(env_logger::Env::default().default_filter_or("info")).init();
+    let env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info"));
+    let subscriber_builder =
+        tracing_subscriber::fmt::Subscriber::builder().with_env_filter(env_filter);
+    let subscriber = subscriber_builder.with_writer(std::io::stderr).finish();
+    set_global_default(subscriber).expect("Failed to set subscriber");
+
     let options = ClientOpt::from_args();
     let send_timeout = Duration::from_micros(options.send_timeout);
     let recv_timeout = Duration::from_micros(options.recv_timeout);

diff --git a/fastpay/src/network.rs b/fastpay/src/network.rs
@@ -8,10 +8,10 @@ use fastx_types::{error::*, messages::*, serialize::*};
 use async_trait::async_trait;
 use bytes::Bytes;
 use futures::future::FutureExt;
-use log::*;
 use std::io;
 use std::sync::atomic::{AtomicUsize, Ordering};
 use tokio::time;
+use tracing::*;
 
 pub struct Server {
     base_address: String,

diff --git a/fastpay/src/server.rs b/fastpay/src/server.rs
@@ -8,11 +8,13 @@ use fastpay_core::authority::*;
 use fastx_types::{base_types::*, committee::Committee, object::Object};
 
 use futures::future::join_all;
-use log::*;
 use std::path::Path;
 use std::sync::Arc;
 use structopt::StructOpt;
 use tokio::runtime::Runtime;
+use tracing::subscriber::set_global_default;
+use tracing::*;
+use tracing_subscriber::EnvFilter;
 
 #[allow(clippy::too_many_arguments)]
 fn make_server(
@@ -118,7 +120,12 @@ enum ServerCommands {
 }
 
 fn main() {
-    env_logger::Builder::from_env(env_logger::Env::default().default_filter_or("info")).init();
+    let env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info"));
+    let subscriber_builder =
+        tracing_subscriber::fmt::Subscriber::builder().with_env_filter(env_filter);
+    let subscriber = subscriber_builder.with_writer(std::io::stderr).finish();
+    set_global_default(subscriber).expect("Failed to set subscriber");
+
     let options = ServerOpt::from_args();
 
     let server_config_path = &options.server;

diff --git a/fastpay/src/transport.rs b/fastpay/src/transport.rs
@@ -2,7 +2,6 @@
 // SPDX-License-Identifier: Apache-2.0
 
 use futures::future;
-use log::*;
 use std::io::ErrorKind;
 use std::{collections::HashMap, convert::TryInto, io, sync::Arc};
 use tokio::io::{AsyncReadExt, AsyncWriteExt};
@@ -11,6 +10,7 @@ use tokio::{
     io::{AsyncRead, AsyncWrite},
     net::{TcpListener, TcpStream},
 };
+use tracing::*;
 
 #[cfg(test)]
 #[path = "unit_tests/transport_tests.rs"]