From 3085eee19f93a937cfb566a5c5f7ce975ad1d67e Mon Sep 17 00:00:00 2001 From: binarybaron <86064887+binarybaron@users.noreply.github.com> Date: Sat, 16 Nov 2024 21:54:02 +0100 Subject: [PATCH] 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 | 2 ++ Cargo.lock | 2 +- swap/src/asb/event_loop.rs | 12 ++++---- swap/src/common/tracing_util.rs | 53 ++++++++++++++++++++++----------- swap/src/kraken.rs | 2 -- 5 files changed, 44 insertions(+), 27 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a1dfd4ef..fa23f88e 100644 --- a/CHANGELOG.md +++ b/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 diff --git a/Cargo.lock b/Cargo.lock index bc47e809..64f4fcbc 100644 --- a/Cargo.lock +++ b/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", diff --git a/swap/src/asb/event_loop.rs b/swap/src/asb/event_loop.rs index efee8b4c..9a103e37 100644 --- a/swap/src/asb/event_loop.rs +++ b/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 ); diff --git a/swap/src/common/tracing_util.rs b/swap/src/common/tracing_util.rs index 7719df57..bad75a4c 100644 --- a/swap/src/common/tracing_util.rs +++ b/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, ) -> 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(()) } diff --git a/swap/src/kraken.rs b/swap/src/kraken.rs index b4562dc6..7bb67bb2 100644 --- a/swap/src/kraken.rs +++ b/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