Updates all logs to use tracing instead (#96)

* Updates all logs to use tracing instead Signed-off-by: Taylor Thomas <[email protected]> * Address PR comments Signed-off-by: Taylor Thomas <[email protected]> * feat(*): Removes channel logger in favor of tracing Signed-off-by: Taylor Thomas <[email protected]>
wasmCloud · Mar 22, 2022 · bac28da · bac28da
1 parent c789836
commit bac28da
Show file tree

Hide file tree

Showing 10 changed files with 197 additions and 404 deletions.
diff --git a/rpc-rs/Cargo.toml b/rpc-rs/Cargo.toml
@@ -25,8 +25,7 @@ chunkify = [ "nats" ]
 async-trait = "0.1"
 base64 = "0.13"
 cfg-if = "1.0"
-log = "0.4"
-minicbor = { version = "0.13", features = ["std", "partial-skip-support" ] }
+minicbor = { version = "0.13", features = ["std", "partial-skip-support"] }
 rmp-serde = { version = "0.15.4" }
 serde_bytes = "0.11"
 serde_json = "1.0"
@@ -35,6 +34,8 @@ thiserror = "1.0"
 time = "0.3.7"
 tokio-timer = "0.2"
 toml = "0.5"
+tracing = { version = "0.1", features = ["log"] }
+tracing-futures = "0.2"
 wasmbus-macros = { path = "../macros", version = "0.1.8" }
 minicbor-ser = "0.1.2"
 
@@ -44,19 +45,18 @@ num-bigint = { version = "0.4", optional = true }
 bigdecimal = { version = "0.3", optional = true }
 
 [target.'cfg(not(target_arch = "wasm32"))'.dependencies]
-tokio = { version = "1", features = ["full"]}
+tokio = { version = "1", features = ["full"] }
 futures = "0.3"
 nats-aflowt = "0.16.104"
-nats = { version = "0.17", optional=true }
+nats = { version = "0.18", optional = true }
 nkeys = "0.2"
 once_cell = "1.8"
-crossbeam = "0.8"
-uuid = { version = "0.8", features=["v4", "serde"] }
+uuid = { version = "0.8", features = ["v4", "serde"] }
 wascap = "0.8.0"
 ring = "0.16"
-pin-utils = "0.1"
 data-encoding = "2.3"
-
+tracing-subscriber = { version = "0.3.7", features = ["env-filter"] }
+atty = "0.2"
 
 [dev-dependencies]
 regex = "1"

diff --git a/rpc-rs/src/channel_log.rs b/rpc-rs/src/channel_log.rs
diff --git a/rpc-rs/src/chunkify.rs b/rpc-rs/src/chunkify.rs
@@ -17,20 +17,23 @@
 //
 // I will always be chunkified ...
 
-use crate::{
-    error::{RpcError, RpcResult},
-    provider_main::get_host_bridge,
+use std::{
+    collections::HashMap,
+    io::Read,
+    sync::{Arc, RwLock},
 };
-use log::{debug, error};
+
 use nats::{
     jetstream::JetStream,
     object_store::{Config, ObjectStore},
     JetStreamOptions,
 };
 use once_cell::sync::OnceCell;
-use std::{
-    collections::HashMap,
-    sync::{Arc, RwLock},
+use tracing::{debug, error, instrument};
+
+use crate::{
+    error::{RpcError, RpcResult},
+    provider_main::get_host_bridge,
 };
 
 /// Maximum size of a message payload before it will be chunked
@@ -72,12 +75,11 @@ impl ChunkEndpoint {
     }
 
     /// load the message after de-chunking
+    #[instrument(level = "trace", skip(self))]
     pub fn get_unchunkified(&self, inv_id: &str) -> RpcResult<Vec<u8>> {
-        use std::io::Read as _;
-
         let mut result = Vec::new();
         let store = self.create_or_reuse_store()?;
-        debug!("chunkify starting to receive: '{}'", inv_id,);
+        debug!(invocation_id = %inv_id, "chunkify starting to receive");
         let mut obj = store.get(inv_id).map_err(|e| {
             RpcError::Nats(format!(
                 "error starting to receive chunked stream for inv {}:{}",
@@ -94,7 +96,7 @@ impl ChunkEndpoint {
         if let Err(e) = store.delete(inv_id) {
             // not deleting will be a non-fatal error for the receiver,
             // if all the bytes have been received
-            error!("deleting chunks for inv {}: {}", inv_id, e);
+            error!(invocation_id = %inv_id, error = %e, "deleting chunks for inv");
         }
         Ok(result)
     }
@@ -106,17 +108,14 @@ impl ChunkEndpoint {
     }
 
     /// chunkify a message
-    pub fn chunkify(&self, inv_id: &str, bytes: &mut impl std::io::Read) -> RpcResult<()> {
+    #[instrument(level = "trace", skip(self, bytes))]
+    pub fn chunkify(&self, inv_id: &str, bytes: &mut impl Read) -> RpcResult<()> {
         let store = self.create_or_reuse_store()?;
-        debug!("chunkify starting to send: '{}'", inv_id,);
+        debug!(invocation_id = %inv_id, "chunkify starting to send");
         let info = store
             .put(inv_id, bytes)
             .map_err(|e| RpcError::Nats(format!("writing chunkified for {}: {}", inv_id, e)))?;
-        // try getting info to confirm it's been written
-        //let _info2 = store
-        //    .info(inv_id)
-        //    .map_err(|e| RpcError::Nats(format!("couldn't read info for {}", inv_id)))?;
-        debug!("chunkify completed writing: '{}': {:?}", inv_id, info);
+        debug!(?info, invocation_id = %inv_id, "chunkify completed writing");
 
         Ok(())
     }

diff --git a/rpc-rs/src/lib.rs b/rpc-rs/src/lib.rs
@@ -9,7 +9,6 @@ mod timestamp;
 pub use timestamp::Timestamp;
 
 mod actor_wasm;
-pub mod channel_log;
 pub mod common;
 pub mod provider;
 pub(crate) mod provider_main;