From ed9f368305116ffe4d08f2a4f5b7b498ecee9610 Mon Sep 17 00:00:00 2001
From: Daniel Karzel <daniel@comit.network>
Date: Fri, 12 Nov 2021 17:36:55 +1100
Subject: [PATCH] Configurable log levels on both taker and maker

Add configurable log levels on taker and maker and start tracing connection related information to track down a problem where the taker does not receive orders but there are not connection errors on both sides.
---
 daemon/src/fan_out.rs               | 6 +++++-
 daemon/src/maker.rs                 | 6 +++++-
 daemon/src/maker_inc_connections.rs | 3 ++-
 daemon/src/oracle.rs                | 1 -
 daemon/src/send_to_socket.rs        | 2 ++
 daemon/src/taker.rs                 | 6 +++++-
 daemon/src/taker_cfd.rs             | 3 +++
 7 files changed, 22 insertions(+), 5 deletions(-)

diff --git a/daemon/src/fan_out.rs b/daemon/src/fan_out.rs
index 04e1236..b6834d2 100644
--- a/daemon/src/fan_out.rs
+++ b/daemon/src/fan_out.rs
@@ -23,7 +23,11 @@ where
     async fn handle(&mut self, message: M, _: &mut xtra::Context<Self>) {
         for receiver in &self.receivers {
             // Not sure why here is no `do_send_async` ...
-            let _ = receiver.do_send(message.clone());
+            if receiver.do_send(message.clone()).is_err() {
+                tracing::error!(
+                    "Fan out actor was unable to send to other actor - we should never see this."
+                )
+            }
         }
     }
 }
diff --git a/daemon/src/maker.rs b/daemon/src/maker.rs
index defbd77..a7bacfb 100644
--- a/daemon/src/maker.rs
+++ b/daemon/src/maker.rs
@@ -48,6 +48,10 @@ struct Opts {
     #[clap(short, long)]
     json: bool,
 
+    /// Configure the log level, e.g.: one of Error, Warn, Info, Debug, Trace
+    #[clap(short, long, default_value = "Debug")]
+    log_level: LevelFilter,
+
     /// The time interval until potential settlement of each CFD in hours
     #[clap(long, default_value = "24")]
     settlement_time_interval_hours: u8,
@@ -142,7 +146,7 @@ impl Network {
 async fn main() -> Result<()> {
     let opts = Opts::parse();
 
-    logger::init(LevelFilter::DEBUG, opts.json).context("initialize logger")?;
+    logger::init(opts.log_level, opts.json).context("initialize logger")?;
     tracing::info!("Running version: {}", env!("VERGEN_GIT_SEMVER_LIGHTWEIGHT"));
 
     let data_dir = opts
diff --git a/daemon/src/maker_inc_connections.rs b/daemon/src/maker_inc_connections.rs
index a548eb7..6d7214b 100644
--- a/daemon/src/maker_inc_connections.rs
+++ b/daemon/src/maker_inc_connections.rs
@@ -151,7 +151,8 @@ impl Actor {
     async fn handle_broadcast_order(&mut self, msg: BroadcastOrder) -> Result<()> {
         let order = msg.0;
 
-        for conn in self.write_connections.values() {
+        for (taker_id, conn) in self.write_connections.clone() {
+            tracing::trace!(%taker_id, "sending new order for broadcast to connection: {:?}", order);
             conn.do_send_async(wire::MakerToTaker::CurrentOrder(order.clone()))
                 .await?;
         }
diff --git a/daemon/src/oracle.rs b/daemon/src/oracle.rs
index 6474a4a..872f6df 100644
--- a/daemon/src/oracle.rs
+++ b/daemon/src/oracle.rs
@@ -112,7 +112,6 @@ impl Actor {
             ));
 
             if self.announcements.get(&event_id).is_some() {
-                tracing::trace!("Announcement already known: {}", event_id,);
                 continue;
             }
             let this = ctx.address().expect("self to be alive");
diff --git a/daemon/src/send_to_socket.rs b/daemon/src/send_to_socket.rs
index 84f5cc5..765fb29 100644
--- a/daemon/src/send_to_socket.rs
+++ b/daemon/src/send_to_socket.rs
@@ -33,6 +33,8 @@ where
     async fn handle(&mut self, message: T, ctx: &mut xtra::Context<Self>) {
         let message_name = message.to_string(); // send consumes the message, avoid a clone just in case it errors by getting the name here
 
+        tracing::trace!(%message_name, "send to socket message");
+
         if let Err(e) = self.write.send(message).await {
             tracing::error!("Failed to write message {} to socket: {}", message_name, e);
             ctx.stop();
diff --git a/daemon/src/taker.rs b/daemon/src/taker.rs
index d34c6f7..b5b41cb 100644
--- a/daemon/src/taker.rs
+++ b/daemon/src/taker.rs
@@ -47,6 +47,10 @@ struct Opts {
     #[clap(short, long)]
     json: bool,
 
+    /// Configure the log level, e.g.: one of Error, Warn, Info, Debug, Trace
+    #[clap(short, long, default_value = "Debug")]
+    log_level: LevelFilter,
+
     #[clap(subcommand)]
     network: Network,
 }
@@ -141,7 +145,7 @@ impl Network {
 async fn main() -> Result<()> {
     let opts = Opts::parse();
 
-    logger::init(LevelFilter::DEBUG, opts.json).context("initialize logger")?;
+    logger::init(opts.log_level, opts.json).context("initialize logger")?;
     tracing::info!("Running version: {}", env!("VERGEN_GIT_SEMVER_LIGHTWEIGHT"));
 
     let data_dir = opts
diff --git a/daemon/src/taker_cfd.rs b/daemon/src/taker_cfd.rs
index 38d36c9..b20d1a4 100644
--- a/daemon/src/taker_cfd.rs
+++ b/daemon/src/taker_cfd.rs
@@ -300,6 +300,7 @@ where
 
 impl<O, M, W> Actor<O, M, W> {
     async fn handle_new_order(&mut self, order: Option<Order>) -> Result<()> {
+        tracing::trace!("new order {:?}", order);
         match order {
             Some(mut order) => {
                 order.origin = Origin::Theirs;
@@ -737,6 +738,8 @@ where
             }
         };
 
+        tracing::trace!("message from maker: {:?}", msg);
+
         match msg {
             wire::MakerToTaker::CurrentOrder(current_order) => {
                 log_error!(self.handle_new_order(current_order))