feat(swap): Log tracing in rolling log files (#155)

We now log verbose messages to hourly rotating `tracing*.log` which are kept for 24 hours. General logs are written to `swap-all.log`.

CHANGELOG.md

@@ -7,6 +7,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+- ASB: We now log verbose messages to hourly rotating `tracing*.log` which are kept for 24 hours. General logs are written to `swap-all.log`.
+
 ## [1.0.0-rc.2] - 2024-11-16
 
 - GUI: ASBs discovered via rendezvous are now prioritized if they are running the latest version

Cargo.lock

@@ -9504,7 +9504,7 @@ dependencies = [
 
 [[package]]
 name = "unstoppableswap-gui-rs"
-version = "1.0.0-rc.2"
+version = "0.7.0"
 dependencies = [
  "anyhow",
  "once_cell",

swap/src/asb/event_loop.rs

@@ -413,7 +413,7 @@ where
                                 "Communication error: {:#}", error);
                         }
                         SwarmEvent::ConnectionEstablished { peer_id: peer, endpoint, .. } => {
-                            tracing::debug!(%peer, address = %endpoint.get_remote_address(), "New connection established");
+                            tracing::trace!(%peer, address = %endpoint.get_remote_address(), "New connection established");
 
                             // If we have buffered transfer proofs for this peer, we can now send them
                             if let Some(transfer_proofs) = self.buffered_transfer_proofs.remove(&peer) {
@@ -429,13 +429,13 @@ where
                             }
                         }
                         SwarmEvent::IncomingConnectionError { send_back_addr: address, error, .. } => {
-                            tracing::warn!(%address, "Failed to set up connection with peer: {:#}", error);
+                            tracing::trace!(%address, "Failed to set up connection with peer: {:#}", error);
                         }
                         SwarmEvent::ConnectionClosed { peer_id: peer, num_established: 0, endpoint, cause: Some(error), connection_id } => {
-                            tracing::debug!(%peer, address = %endpoint.get_remote_address(), %connection_id, "Lost connection to peer: {:#}", error);
+                            tracing::trace!(%peer, address = %endpoint.get_remote_address(), %connection_id, "Lost connection to peer: {:#}", error);
                         }
                         SwarmEvent::ConnectionClosed { peer_id: peer, num_established: 0, endpoint, cause: None, connection_id } => {
-                            tracing::info!(%peer, address = %endpoint.get_remote_address(), %connection_id,  "Successfully closed connection");
+                            tracing::trace!(%peer, address = %endpoint.get_remote_address(), %connection_id,  "Successfully closed connection");
                         }
                         SwarmEvent::NewListenAddr{address, ..} => {
                             tracing::info!(%address, "New listen address reported");
@@ -493,7 +493,7 @@ where
         tracing::debug!(%ask_price, %xmr_balance, %max_bitcoin_for_monero, "Computed quote");
 
         if min_buy > max_bitcoin_for_monero {
-            tracing::warn!(
+            tracing::trace!(
                         "Your Monero balance is too low to initiate a swap, as your minimum swap amount is {}. You could at most swap {}",
                         min_buy, max_bitcoin_for_monero
                     );
@@ -506,7 +506,7 @@ where
         }
 
         if max_buy > max_bitcoin_for_monero {
-            tracing::warn!(
+            tracing::trace!(
                     "Your Monero balance is too low to initiate a swap with the maximum swap amount {} that you have specified in your config. You can at most swap {}",
                     max_buy, max_bitcoin_for_monero
                 );

swap/src/common/tracing_util.rs

@@ -3,6 +3,7 @@ use std::path::Path;
 use std::str::FromStr;
 
 use anyhow::Result;
+use tracing_appender::rolling::{RollingFileAppender, Rotation};
 use tracing_subscriber::filter::{Directive, LevelFilter};
 use tracing_subscriber::fmt::time::UtcTime;
 use tracing_subscriber::fmt::MakeWriter;
@@ -31,8 +32,17 @@ pub fn init(
     tauri_handle: Option<TauriHandle>,
 ) -> Result<()> {
     // file logger will always write in JSON format and with timestamps
-    let file_appender = tracing_appender::rolling::never(&dir, "swap-all.log");
+    let file_appender: RollingFileAppender = tracing_appender::rolling::never(&dir, "swap-all.log");
 
+    let tracing_file_appender: RollingFileAppender = RollingFileAppender::builder()
+        .rotation(Rotation::HOURLY)
+        .filename_prefix("tracing")
+        .filename_suffix("log")
+        .max_log_files(24)
+        .build(&dir)
+        .expect("initializing rolling file appender failed");
+
+    // Log to file
     let file_layer = fmt::layer()
         .with_writer(file_appender)
         .with_ansi(false)
@@ -41,7 +51,15 @@ pub fn init(
         .json()
         .with_filter(env_filter(level_filter)?);
 
-    // terminal loger
+    let tracing_file_layer = fmt::layer()
+        .with_writer(tracing_file_appender)
+        .with_ansi(false)
+        .with_timer(UtcTime::rfc_3339())
+        .with_target(false)
+        .json()
+        .with_filter(env_filter(LevelFilter::TRACE)?);
+
+    // Log to stdout
     let is_terminal = atty::is(atty::Stream::Stderr);
     let terminal_layer = fmt::layer()
         .with_writer(std::io::stdout)
@@ -49,7 +67,7 @@ pub fn init(
         .with_timer(UtcTime::rfc_3339())
         .with_target(false);
 
-    // tauri layer (forwards logs to the tauri guest when connected)
+    // Forwards logs to the tauri guest
     let tauri_layer = fmt::layer()
         .with_writer(TauriWriter::new(tauri_handle))
         .with_ansi(false)
@@ -58,23 +76,22 @@ pub fn init(
         .json()
         .with_filter(env_filter(level_filter)?);
 
-    // combine the layers and start logging, format with json if specified
-    if let Format::Json = format {
-        tracing_subscriber::registry()
-            .with(file_layer)
-            .with(tauri_layer)
-            .with(terminal_layer.json().with_filter(env_filter(level_filter)?))
-            .try_init()?;
-    } else {
-        tracing_subscriber::registry()
-            .with(file_layer)
-            .with(tauri_layer)
-            .with(terminal_layer.with_filter(env_filter(level_filter)?))
-            .try_init()?;
-    }
+    let env_filtered = env_filter(level_filter)?;
+
+    let final_terminal_layer = match format {
+        Format::Json => terminal_layer.json().with_filter(env_filtered).boxed(),
+        Format::Raw => terminal_layer.with_filter(env_filtered).boxed(),
+    };
+
+    tracing_subscriber::registry()
+        .with(file_layer)
+        .with(tracing_file_layer)
+        .with(final_terminal_layer)
+        .with(tauri_layer)
+        .try_init()?;
 
     // Now we can use the tracing macros to log messages
-    tracing::info!(%level_filter, logs_dir=%dir.as_ref().display(), "Initialized tracing");
+    tracing::info!(%level_filter, logs_dir=%dir.as_ref().display(), "Initialized tracing. General logs will be written to swap-all.log, and verbose logs to tracing*.log");
 
     Ok(())
 }

swap/src/kraken.rs

@@ -186,8 +186,6 @@ mod connection {
                 return Ok(None);
             }
             Ok(wire::Event::Heartbeat) => {
-                tracing::trace!("Received heartbeat message");
-
                 return Ok(None);
             }
             // if the message is not an event, it is a ticker update or an unknown event