From e517c5934ed8a3fdc9958d09fbb5d4dbb8e569aa Mon Sep 17 00:00:00 2001 From: rishflab Date: Fri, 26 Mar 2021 16:27:13 +1100 Subject: [PATCH 1/3] Move asb tracing initializer to asb module --- swap/src/asb.rs | 1 + swap/src/{ => asb}/trace.rs | 0 swap/src/bin/asb.rs | 2 +- swap/src/lib.rs | 1 - 4 files changed, 2 insertions(+), 2 deletions(-) rename swap/src/{ => asb}/trace.rs (100%) diff --git a/swap/src/asb.rs b/swap/src/asb.rs index 262f8a6a..118c992a 100644 --- a/swap/src/asb.rs +++ b/swap/src/asb.rs @@ -1,5 +1,6 @@ pub mod command; pub mod config; mod rate; +pub mod trace; pub use rate::Rate; diff --git a/swap/src/trace.rs b/swap/src/asb/trace.rs similarity index 100% rename from swap/src/trace.rs rename to swap/src/asb/trace.rs diff --git a/swap/src/bin/asb.rs b/swap/src/bin/asb.rs index 3140d946..7550f2d2 100644 --- a/swap/src/bin/asb.rs +++ b/swap/src/bin/asb.rs @@ -21,6 +21,7 @@ use swap::asb::command::{Arguments, Command}; use swap::asb::config::{ initial_setup, query_user_for_initial_testnet_config, read_config, Config, ConfigNotInitialized, }; +use swap::asb::trace::init_tracing; use swap::database::Database; use swap::env::GetConfig; use swap::fs::default_config_path; @@ -29,7 +30,6 @@ use swap::network::swarm; use swap::protocol::alice::event_loop::KrakenRate; use swap::protocol::alice::{run, Behaviour, EventLoop}; use swap::seed::Seed; -use swap::trace::init_tracing; use swap::{bitcoin, env, kraken, monero}; use tracing::{info, warn}; use tracing_subscriber::filter::LevelFilter; diff --git a/swap/src/lib.rs b/swap/src/lib.rs index 51aa3c79..4af15cc1 100644 --- a/swap/src/lib.rs +++ b/swap/src/lib.rs @@ -27,6 +27,5 @@ pub mod monero; pub mod network; pub mod protocol; pub mod seed; -pub mod trace; mod monero_ext; From 9745d150e7481cd50124c8c2522bee1b7c7e5b01 Mon Sep 17 00:00:00 2001 From: rishflab Date: Fri, 2 Apr 2021 18:22:51 +1100 Subject: [PATCH 2/3] 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); + } + } +} From 8805002f96b261b067a45a060ab6d1dba3d3fbb7 Mon Sep 17 00:00:00 2001 From: rishflab Date: Thu, 8 Apr 2021 13:09:52 +1000 Subject: [PATCH 3/3] Remove redundant noun from tracing initialiser functions --- swap/src/asb.rs | 2 +- swap/src/asb/{trace.rs => tracing.rs} | 2 +- swap/src/bin/asb.rs | 5 ++--- swap/src/bin/swap.rs | 11 +++++------ swap/src/cli.rs | 2 +- swap/src/cli/{trace.rs => tracing.rs} | 2 +- 6 files changed, 11 insertions(+), 13 deletions(-) rename swap/src/asb/{trace.rs => tracing.rs} (91%) rename swap/src/cli/{trace.rs => tracing.rs} (96%) diff --git a/swap/src/asb.rs b/swap/src/asb.rs index 118c992a..222046c1 100644 --- a/swap/src/asb.rs +++ b/swap/src/asb.rs @@ -1,6 +1,6 @@ pub mod command; pub mod config; mod rate; -pub mod trace; +pub mod tracing; pub use rate::Rate; diff --git a/swap/src/asb/trace.rs b/swap/src/asb/tracing.rs similarity index 91% rename from swap/src/asb/trace.rs rename to swap/src/asb/tracing.rs index 70728fd6..dd27194c 100644 --- a/swap/src/asb/trace.rs +++ b/swap/src/asb/tracing.rs @@ -2,7 +2,7 @@ use anyhow::Result; use tracing_subscriber::filter::LevelFilter; use tracing_subscriber::FmtSubscriber; -pub fn init_tracing(level: LevelFilter) -> Result<()> { +pub fn init(level: LevelFilter) -> Result<()> { if level == LevelFilter::OFF { return Ok(()); } diff --git a/swap/src/bin/asb.rs b/swap/src/bin/asb.rs index 7550f2d2..61908b92 100644 --- a/swap/src/bin/asb.rs +++ b/swap/src/bin/asb.rs @@ -21,7 +21,6 @@ use swap::asb::command::{Arguments, Command}; use swap::asb::config::{ initial_setup, query_user_for_initial_testnet_config, read_config, Config, ConfigNotInitialized, }; -use swap::asb::trace::init_tracing; use swap::database::Database; use swap::env::GetConfig; use swap::fs::default_config_path; @@ -30,7 +29,7 @@ use swap::network::swarm; use swap::protocol::alice::event_loop::KrakenRate; use swap::protocol::alice::{run, Behaviour, EventLoop}; use swap::seed::Seed; -use swap::{bitcoin, env, kraken, monero}; +use swap::{asb, bitcoin, env, kraken, monero}; use tracing::{info, warn}; use tracing_subscriber::filter::LevelFilter; @@ -41,7 +40,7 @@ const DEFAULT_WALLET_NAME: &str = "asb-wallet"; #[tokio::main] async fn main() -> Result<()> { - init_tracing(LevelFilter::DEBUG).expect("initialize tracing"); + asb::tracing::init(LevelFilter::DEBUG).expect("initialize tracing"); let opt = Arguments::from_args(); diff --git a/swap/src/bin/swap.rs b/swap/src/bin/swap.rs index af6cb748..99b199df 100644 --- a/swap/src/bin/swap.rs +++ b/swap/src/bin/swap.rs @@ -22,7 +22,6 @@ use std::time::Duration; use structopt::StructOpt; use swap::bitcoin::{Amount, TxLock}; 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,7 +29,7 @@ use swap::network::swarm; use swap::protocol::bob; use swap::protocol::bob::{Behaviour, Builder, EventLoop}; use swap::seed::Seed; -use swap::{bitcoin, env, monero}; +use swap::{bitcoin, cli, env, monero}; use tracing::{debug, error, info, warn}; use url::Url; use uuid::Uuid; @@ -56,7 +55,7 @@ async fn main() -> Result<()> { let swap_id = Uuid::new_v4(); let data_dir = data.0; - init_tracing(debug, data_dir.join("logs"), swap_id)?; + cli::tracing::init(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()) @@ -153,7 +152,7 @@ async fn main() -> Result<()> { electrum_rpc_url, } => { let data_dir = data.0; - init_tracing(debug, data_dir.join("logs"), swap_id)?; + cli::tracing::init(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()) @@ -204,7 +203,7 @@ async fn main() -> Result<()> { electrum_rpc_url, } => { let data_dir = data.0; - init_tracing(debug, data_dir.join("logs"), swap_id)?; + cli::tracing::init(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()) @@ -234,7 +233,7 @@ async fn main() -> Result<()> { electrum_rpc_url, } => { let data_dir = data.0; - init_tracing(debug, data_dir.join("logs"), swap_id)?; + cli::tracing::init(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()) diff --git a/swap/src/cli.rs b/swap/src/cli.rs index 2411d2d2..e28b6580 100644 --- a/swap/src/cli.rs +++ b/swap/src/cli.rs @@ -1,2 +1,2 @@ pub mod command; -pub mod trace; +pub mod tracing; diff --git a/swap/src/cli/trace.rs b/swap/src/cli/tracing.rs similarity index 96% rename from swap/src/cli/trace.rs rename to swap/src/cli/tracing.rs index 8ff16bd1..82ee2594 100644 --- a/swap/src/cli/trace.rs +++ b/swap/src/cli/tracing.rs @@ -8,7 +8,7 @@ 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<()> { +pub fn init(debug: bool, dir: impl AsRef, swap_id: Uuid) -> Result<()> { let level_filter = EnvFilter::try_new("swap=debug")?; let registry = Registry::default().with(level_filter);