From 9745d150e7481cd50124c8c2522bee1b7c7e5b01 Mon Sep 17 00:00:00 2001 From: rishflab Date: Fri, 2 Apr 2021 18:22:51 +1100 Subject: [PATCH] Log at debug level to file EnvFilter is applied globally. This means you cannot log at INFO level to the terminal and at DEBUG level to log files. To get a around this limitation I had to implement the layer trait on a new type and filter in the on_event() trait method. Each swap has its own log file denoted by its swap_id. The logger appends to the existing file when resuming a swap. Closes #278 --- Cargo.lock | 23 ++++++++++++ swap/Cargo.toml | 1 + swap/src/bin/swap.rs | 87 ++++++++++++++++++++++--------------------- swap/src/cli.rs | 1 + swap/src/cli/trace.rs | 81 ++++++++++++++++++++++++++++++++++++++++ 5 files changed, 150 insertions(+), 43 deletions(-) create mode 100644 swap/src/cli/trace.rs diff --git a/Cargo.lock b/Cargo.lock index 3cde7b4f..4c5d0ee7 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -620,6 +620,7 @@ dependencies = [ "libc", "num-integer", "num-traits", + "time 0.1.43", "winapi 0.3.9", ] @@ -722,6 +723,16 @@ dependencies = [ "cfg-if 1.0.0", ] +[[package]] +name = "crossbeam-channel" +version = "0.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "dca26ee1f8d361640700bde38b2c37d8c22b3ce2d360e1fc1c74ea4b0aa7d775" +dependencies = [ + "cfg-if 1.0.0", + "crossbeam-utils", +] + [[package]] name = "crossbeam-epoch" version = "0.9.3" @@ -3614,6 +3625,7 @@ dependencies = [ "tokio-util", "toml", "tracing", + "tracing-appender", "tracing-futures", "tracing-subscriber", "url 2.2.1", @@ -3958,6 +3970,17 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-appender" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9965507e507f12c8901432a33e31131222abac31edd90cabbcf85cf544b7127a" +dependencies = [ + "chrono", + "crossbeam-channel", + "tracing-subscriber", +] + [[package]] name = "tracing-attributes" version = "0.1.15" diff --git a/swap/Cargo.toml b/swap/Cargo.toml index 742249c0..d7aa117d 100644 --- a/swap/Cargo.toml +++ b/swap/Cargo.toml @@ -53,6 +53,7 @@ tokio-tungstenite = { version = "0.14", features = [ "rustls-tls" ] } tokio-util = { version = "0.6", features = ["io"] } toml = "0.5" tracing = { version = "0.1", features = ["attributes"] } +tracing-appender = "0.1" tracing-futures = { version = "0.2", features = ["std-future", "futures-03"] } tracing-subscriber = { version = "0.2", default-features = false, features = ["fmt", "ansi", "env-filter", "chrono", "tracing-log"] } url = { version = "2", features = ["serde"] } diff --git a/swap/src/bin/swap.rs b/swap/src/bin/swap.rs index ed74a4c0..af6cb748 100644 --- a/swap/src/bin/swap.rs +++ b/swap/src/bin/swap.rs @@ -21,7 +21,8 @@ use std::sync::Arc; use std::time::Duration; use structopt::StructOpt; use swap::bitcoin::{Amount, TxLock}; -use swap::cli::command::{Arguments, Command, Data, MoneroParams}; +use swap::cli::command::{Arguments, Command, MoneroParams}; +use swap::cli::trace::init_tracing; use swap::database::Database; use swap::env::{Config, GetConfig}; use swap::network::quote::BidQuote; @@ -30,8 +31,7 @@ use swap::protocol::bob; use swap::protocol::bob::{Behaviour, Builder, EventLoop}; use swap::seed::Seed; use swap::{bitcoin, env, monero}; -use tracing::{debug, error, info, warn, Level}; -use tracing_subscriber::FmtSubscriber; +use tracing::{debug, error, info, warn}; use url::Url; use uuid::Uuid; @@ -40,46 +40,9 @@ extern crate prettytable; #[tokio::main] async fn main() -> Result<()> { - let args = Arguments::from_args(); + let Arguments { data, debug, cmd } = Arguments::from_args(); - let is_terminal = atty::is(atty::Stream::Stderr); - let base_subscriber = |level| { - FmtSubscriber::builder() - .with_writer(std::io::stderr) - .with_ansi(is_terminal) - .with_target(false) - .with_env_filter(format!("swap={}", level)) - }; - - if args.debug { - let subscriber = base_subscriber(Level::DEBUG) - .with_timer(tracing_subscriber::fmt::time::ChronoLocal::with_format( - "%F %T".to_owned(), - )) - .finish(); - - tracing::subscriber::set_global_default(subscriber)?; - } else { - let subscriber = base_subscriber(Level::INFO) - .without_time() - .with_level(false) - .finish(); - - tracing::subscriber::set_global_default(subscriber)?; - } - - let data: Data = args.data; - let data_dir = data.0; - - let db = - Database::open(data_dir.join("database").as_path()).context("Failed to open database")?; - - let seed = - Seed::from_file_or_generate(data_dir.as_path()).context("Failed to read in seed file")?; - - let env_config = env::Testnet::get_config(); - - match args.cmd { + match cmd { Command::BuyXmr { alice_peer_id, alice_multiaddr, @@ -90,6 +53,16 @@ async fn main() -> Result<()> { }, electrum_rpc_url, } => { + let swap_id = Uuid::new_v4(); + + let data_dir = data.0; + init_tracing(debug, data_dir.join("logs"), swap_id)?; + let db = Database::open(data_dir.join("database").as_path()) + .context("Failed to open database")?; + let seed = Seed::from_file_or_generate(data_dir.as_path()) + .context("Failed to read in seed file")?; + let env_config = env::Testnet::get_config(); + if receive_monero_address.network != env_config.monero_network { bail!( "Given monero address is on network {:?}, expected address on network {:?}", @@ -128,7 +101,6 @@ async fn main() -> Result<()> { ) .await?; - let swap_id = Uuid::new_v4(); db.insert_peer_id(swap_id, alice_peer_id).await?; let swap = Builder::new( @@ -154,6 +126,11 @@ async fn main() -> Result<()> { } } Command::History => { + let data_dir = data.0; + + let db = Database::open(data_dir.join("database").as_path()) + .context("Failed to open database")?; + let mut table = Table::new(); table.add_row(row!["SWAP ID", "STATE"]); @@ -175,6 +152,14 @@ async fn main() -> Result<()> { }, electrum_rpc_url, } => { + let data_dir = data.0; + init_tracing(debug, data_dir.join("logs"), swap_id)?; + let db = Database::open(data_dir.join("database").as_path()) + .context("Failed to open database")?; + let seed = Seed::from_file_or_generate(data_dir.as_path()) + .context("Failed to read in seed file")?; + let env_config = env::Testnet::get_config(); + if receive_monero_address.network != env_config.monero_network { bail!("The given monero address is on network {:?}, expected address of network {:?}.", receive_monero_address.network, env_config.monero_network) } @@ -218,6 +203,14 @@ async fn main() -> Result<()> { force, electrum_rpc_url, } => { + let data_dir = data.0; + init_tracing(debug, data_dir.join("logs"), swap_id)?; + let db = Database::open(data_dir.join("database").as_path()) + .context("Failed to open database")?; + let seed = Seed::from_file_or_generate(data_dir.as_path()) + .context("Failed to read in seed file")?; + let env_config = env::Testnet::get_config(); + let bitcoin_wallet = init_bitcoin_wallet(electrum_rpc_url, &seed, data_dir, env_config).await?; @@ -240,6 +233,14 @@ async fn main() -> Result<()> { force, electrum_rpc_url, } => { + let data_dir = data.0; + init_tracing(debug, data_dir.join("logs"), swap_id)?; + let db = Database::open(data_dir.join("database").as_path()) + .context("Failed to open database")?; + let seed = Seed::from_file_or_generate(data_dir.as_path()) + .context("Failed to read in seed file")?; + let env_config = env::Testnet::get_config(); + let bitcoin_wallet = init_bitcoin_wallet(electrum_rpc_url, &seed, data_dir, env_config).await?; diff --git a/swap/src/cli.rs b/swap/src/cli.rs index 9fe79612..2411d2d2 100644 --- a/swap/src/cli.rs +++ b/swap/src/cli.rs @@ -1 +1,2 @@ pub mod command; +pub mod trace; diff --git a/swap/src/cli/trace.rs b/swap/src/cli/trace.rs new file mode 100644 index 00000000..8ff16bd1 --- /dev/null +++ b/swap/src/cli/trace.rs @@ -0,0 +1,81 @@ +use anyhow::Result; +use std::path::Path; +use tracing::subscriber::set_global_default; +use tracing::{Event, Level, Subscriber}; +use tracing_subscriber::fmt::format::{DefaultFields, Format}; +use tracing_subscriber::fmt::time::ChronoLocal; +use tracing_subscriber::layer::{Context, SubscriberExt}; +use tracing_subscriber::{fmt, EnvFilter, Layer, Registry}; +use uuid::Uuid; + +pub fn init_tracing(debug: bool, dir: impl AsRef, swap_id: Uuid) -> Result<()> { + let level_filter = EnvFilter::try_new("swap=debug")?; + + let registry = Registry::default().with(level_filter); + + let appender = tracing_appender::rolling::never(dir, format!("swap-{}.log", swap_id)); + let (appender, guard) = tracing_appender::non_blocking(appender); + + std::mem::forget(guard); + + let file_logger = fmt::layer() + .with_ansi(false) + .with_target(false) + .with_writer(appender); + + if debug { + set_global_default(registry.with(file_logger).with(debug_terminal_printer()))?; + } else { + set_global_default(registry.with(file_logger).with(info_terminal_printer()))?; + } + Ok(()) +} + +pub struct StdErrPrinter { + inner: L, + level: Level, +} + +type StdErrLayer = tracing_subscriber::fmt::Layer< + S, + DefaultFields, + Format, + fn() -> std::io::Stderr, +>; + +fn debug_terminal_printer() -> StdErrPrinter> { + let is_terminal = atty::is(atty::Stream::Stderr); + StdErrPrinter { + inner: fmt::layer() + .with_ansi(is_terminal) + .with_target(false) + .with_timer(ChronoLocal::with_format("%F %T".to_owned())) + .with_writer(std::io::stderr), + level: Level::DEBUG, + } +} + +fn info_terminal_printer() -> StdErrPrinter> { + let is_terminal = atty::is(atty::Stream::Stderr); + StdErrPrinter { + inner: fmt::layer() + .with_ansi(is_terminal) + .with_target(false) + .with_level(false) + .without_time() + .with_writer(std::io::stderr), + level: Level::INFO, + } +} + +impl Layer for StdErrPrinter +where + L: 'static + Layer, + S: Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>, +{ + fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) { + if self.level.ge(event.metadata().level()) { + self.inner.on_event(event, ctx); + } + } +}