From 7871cf256b62d7d6fcb056c6b12d3470934f02fa Mon Sep 17 00:00:00 2001 From: Einliterflasche <81313171+Einliterflasche@users.noreply.github.com> Date: Wed, 21 Aug 2024 16:33:04 +0200 Subject: [PATCH] feat(asb + cli): Redact logs + unify tracing infrastructure (#1733) --- .cargo/config.toml | 4 + CHANGELOG.md | 3 + Cargo.lock | 39 ++++-- monero-harness/Cargo.toml | 2 +- swap/Cargo.toml | 2 + swap/src/api.rs | 14 +- swap/src/api/request.rs | 28 ++++ swap/src/asb.rs | 1 - swap/src/asb/command.rs | 69 +++++----- swap/src/asb/tracing.rs | 30 ----- swap/src/bin/asb.rs | 47 +++++-- swap/src/cli.rs | 1 - swap/src/cli/command.rs | 35 +++++ swap/src/cli/tracing.rs | 112 ---------------- swap/src/common.rs | 56 -------- swap/src/common/mod.rs | 221 ++++++++++++++++++++++++++++++++ swap/src/common/tracing_util.rs | 64 +++++++++ swap/src/database/sqlite.rs | 5 +- swap/src/rpc/methods.rs | 28 +++- swap/src/seed.rs | 4 +- 20 files changed, 505 insertions(+), 260 deletions(-) delete mode 100644 swap/src/asb/tracing.rs delete mode 100644 swap/src/cli/tracing.rs delete mode 100644 swap/src/common.rs create mode 100644 swap/src/common/mod.rs create mode 100644 swap/src/common/tracing_util.rs diff --git a/.cargo/config.toml b/.cargo/config.toml index 0c1c209f..b707df9d 100644 --- a/.cargo/config.toml +++ b/.cargo/config.toml @@ -1,2 +1,6 @@ [target.armv7-unknown-linux-gnueabihf] linker = "arm-linux-gnueabihf-gcc" + +# windows defaults to smaller stack sizes which isn't enough +[target.'cfg(windows)'] +rustflags = ["-C", "link-args=/STACK:8388608"] diff --git a/CHANGELOG.md b/CHANGELOG.md index bb8e53e6..c22e533e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +- ASB + CLI: You can now use the `logs` command to retrieve logs stored in the past, redacting addresses and id's using `logs --redact`. +- ASB: The `--disable-timestamp` flag has been removed + ## [0.13.4] - 2024-07-25 - ASB: The `history` command can now be used while the asb is running. diff --git a/Cargo.lock b/Cargo.lock index f6ef4952..f0997737 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -78,6 +78,15 @@ dependencies = [ "memchr", ] +[[package]] +name = "aho-corasick" +version = "1.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8e60d3430d3a69478ad0993f19238d2df97c507009a52b3c10addcd7f6bcb916" +dependencies = [ + "memchr", +] + [[package]] name = "ansi_term" version = "0.11.0" @@ -1500,7 +1509,7 @@ version = "0.4.10" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "029d74589adefde59de1a0c4f4732695c32805624aec7b68d91503d4dba79afc" dependencies = [ - "aho-corasick", + "aho-corasick 0.7.18", "bstr", "fnv", "log", @@ -2508,7 +2517,7 @@ version = "0.0.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "f099785f7595cc4b4553a174ce30dd7589ef93391ff414dbb67f62392b9e0ce1" dependencies = [ - "regex-automata", + "regex-automata 0.1.9", ] [[package]] @@ -2517,7 +2526,7 @@ version = "0.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558" dependencies = [ - "regex-automata", + "regex-automata 0.1.9", ] [[package]] @@ -2653,7 +2662,7 @@ dependencies = [ "testcontainers", "tokio", "tracing", - "tracing-subscriber 0.2.25", + "tracing-subscriber 0.3.18", ] [[package]] @@ -3449,13 +3458,14 @@ dependencies = [ [[package]] name = "regex" -version = "1.7.3" +version = "1.10.5" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8b1f693b24f6ac912f4893ef08244d70b6067480d2f1a46e950c9691e6749d1d" +checksum = "b91213439dad192326a0d7c6ee3955910425f441d7038e0d6933b0aec5c4517f" dependencies = [ - "aho-corasick", + "aho-corasick 1.1.3", "memchr", - "regex-syntax 0.6.29", + "regex-automata 0.4.7", + "regex-syntax 0.8.2", ] [[package]] @@ -3468,6 +3478,17 @@ dependencies = [ "regex-syntax 0.6.29", ] +[[package]] +name = "regex-automata" +version = "0.4.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "38caf58cc5ef2fed281f89292ef23f6365465ed9a41b7a7754eb4e26496c92df" +dependencies = [ + "aho-corasick 1.1.3", + "memchr", + "regex-syntax 0.8.2", +] + [[package]] name = "regex-syntax" version = "0.6.29" @@ -4557,12 +4578,14 @@ dependencies = [ "monero", "monero-harness", "monero-rpc", + "once_cell", "pem", "port_check", "proptest", "qrcode", "rand 0.8.3", "rand_chacha 0.3.1", + "regex", "reqwest", "rust_decimal", "rust_decimal_macros", diff --git a/monero-harness/Cargo.toml b/monero-harness/Cargo.toml index 1151f47a..e15c751d 100644 --- a/monero-harness/Cargo.toml +++ b/monero-harness/Cargo.toml @@ -13,4 +13,4 @@ rand = "0.7" testcontainers = "0.15" tokio = { version = "1", default-features = false, features = [ "rt-multi-thread", "time", "macros" ] } tracing = "0.1" -tracing-subscriber = { version = "0.2", default-features = false, features = [ "fmt", "ansi", "env-filter", "tracing-log" ] } +tracing-subscriber = { version = "0.3", default-features = false, features = [ "fmt", "ansi", "env-filter", "tracing-log" ] } diff --git a/swap/Cargo.toml b/swap/Cargo.toml index f7837c6a..8354ec0a 100644 --- a/swap/Cargo.toml +++ b/swap/Cargo.toml @@ -37,11 +37,13 @@ jsonrpsee-core = "0.16.2" libp2p = { version = "0.42.2", default-features = false, features = [ "tcp-tokio", "yamux", "mplex", "dns-tokio", "noise", "request-response", "websocket", "ping", "rendezvous", "identify" ] } monero = { version = "0.12", features = [ "serde_support" ] } monero-rpc = { path = "../monero-rpc" } +once_cell = "1.19" pem = "3.0" proptest = "1" qrcode = "0.14" rand = "0.8" rand_chacha = "0.3" +regex = "1.10" reqwest = { version = "0.12", features = [ "http2", "rustls-tls", "stream", "socks" ], default-features = false } rust_decimal = { version = "1", features = [ "serde-float" ] } rust_decimal_macros = "1" diff --git a/swap/src/api.rs b/swap/src/api.rs index a87db7c5..ea87aae3 100644 --- a/swap/src/api.rs +++ b/swap/src/api.rs @@ -1,12 +1,13 @@ pub mod request; use crate::cli::command::{Bitcoin, Monero, Tor}; +use crate::common::tracing_util::Format; use crate::database::{open_db, AccessMode}; use crate::env::{Config as EnvConfig, GetConfig, Mainnet, Testnet}; use crate::fs::system_data_dir; use crate::network::rendezvous::XmrBtcNamespace; use crate::protocol::Database; use crate::seed::Seed; -use crate::{bitcoin, cli, monero}; +use crate::{bitcoin, common, monero}; use anyhow::{bail, Context as AnyContext, Error, Result}; use futures::future::try_join_all; use std::fmt; @@ -16,6 +17,8 @@ use std::path::PathBuf; use std::sync::{Arc, Once}; use tokio::sync::{broadcast, broadcast::Sender, Mutex, RwLock}; use tokio::task::JoinHandle; +use tracing::level_filters::LevelFilter; +use tracing::Level; use url::Url; static START: Once = Once::new(); @@ -186,8 +189,15 @@ impl Context { let data_dir = data::data_dir_from(data, is_testnet)?; let env_config = env_config_from(is_testnet); + let format = if json { Format::Json } else { Format::Raw }; + let level_filter = if debug { + LevelFilter::from_level(Level::DEBUG) + } else { + LevelFilter::from_level(Level::INFO) + }; + START.call_once(|| { - let _ = cli::tracing::init(debug, json, data_dir.join("logs")); + let _ = common::tracing_util::init(level_filter, format, data_dir.join("logs")); }); let seed = Seed::from_file_or_generate(data_dir.as_path()) diff --git a/swap/src/api/request.rs b/swap/src/api/request.rs index d47e9a0d..33e261d3 100644 --- a/swap/src/api/request.rs +++ b/swap/src/api/request.rs @@ -1,6 +1,7 @@ use crate::api::Context; use crate::bitcoin::{Amount, ExpiredTimelocks, TxLock}; use crate::cli::{list_sellers, EventLoop, SellerStatus}; +use crate::common::get_logs; use crate::libp2p_ext::MultiAddrExt; use crate::network::quote::{BidQuote, ZeroQuoteReceived}; use crate::network::swarm; @@ -19,6 +20,7 @@ use std::cmp::min; use std::convert::TryInto; use std::future::Future; use std::net::SocketAddr; +use std::path::PathBuf; use std::sync::Arc; use std::time::Duration; use tracing::{debug_span, field, Instrument, Span}; @@ -48,6 +50,11 @@ pub enum Method { swap_id: Uuid, }, History, + Logs { + logs_dir: Option, + redact: bool, + swap_id: Option, + }, Config, WithdrawBtc { amount: Option, @@ -125,6 +132,13 @@ impl Method { log_reference_id = field::Empty ) } + Method::Logs { .. } => { + debug_span!( + "method", + method_name = "Logs", + log_reference_id = field::Empty + ) + } Method::ListSellers { .. } => { debug_span!( "method", @@ -733,6 +747,20 @@ impl Request { Ok(json!({"swaps": json_results})) } + Method::Logs { + logs_dir, + redact, + swap_id, + } => { + let dir = logs_dir.unwrap_or(context.config.data_dir.join("logs")); + let logs = get_logs(dir, swap_id, redact).await?; + + for msg in &logs { + println!("{msg}"); + } + + Ok(json!({ "logs": logs })) + } Method::GetRawStates => { let raw_history = context.db.raw_all().await?; diff --git a/swap/src/asb.rs b/swap/src/asb.rs index b5ed8ac1..404a3b61 100644 --- a/swap/src/asb.rs +++ b/swap/src/asb.rs @@ -4,7 +4,6 @@ mod event_loop; mod network; mod rate; mod recovery; -pub mod tracing; pub use event_loop::{EventLoop, EventLoopHandle, FixedRate, KrakenRate, LatestRate}; pub use network::behaviour::{Behaviour, OutEvent}; diff --git a/swap/src/asb/command.rs b/swap/src/asb/command.rs index 260b5e9d..67565065 100644 --- a/swap/src/asb/command.rs +++ b/swap/src/asb/command.rs @@ -19,7 +19,6 @@ where let args = RawArguments::from_clap(&matches); let json = args.json; - let disable_timestamp = args.disable_timestamp; let testnet = args.testnet; let config = args.config; let command: RawCommand = args.cmd; @@ -28,7 +27,6 @@ where RawCommand::Start { resume_only } => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::Start { resume_only }, @@ -36,15 +34,28 @@ where RawCommand::History { only_unfinished } => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::History { only_unfinished }, }, + RawCommand::Logs { + logs_dir: dir_path, + swap_id, + redact, + } => Arguments { + testnet, + json, + config_path: config_path(config, testnet)?, + env_config: env_config(testnet), + cmd: Command::Logs { + logs_dir: dir_path, + swap_id, + redact, + }, + }, RawCommand::WithdrawBtc { amount, address } => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::WithdrawBtc { @@ -55,7 +66,6 @@ where RawCommand::Balance => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::Balance, @@ -63,7 +73,6 @@ where RawCommand::Config => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::Config, @@ -71,7 +80,6 @@ where RawCommand::ExportBitcoinWallet => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::ExportBitcoinWallet, @@ -82,7 +90,6 @@ where }) => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::Redeem { @@ -96,7 +103,6 @@ where }) => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::Cancel { swap_id }, @@ -106,7 +112,6 @@ where }) => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::Refund { swap_id }, @@ -116,7 +121,6 @@ where }) => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::Punish { swap_id }, @@ -124,7 +128,6 @@ where RawCommand::ManualRecovery(ManualRecovery::SafelyAbort { swap_id }) => Arguments { testnet, json, - disable_timestamp, config_path: config_path(config, testnet)?, env_config: env_config(testnet), cmd: Command::SafelyAbort { swap_id }, @@ -184,7 +187,6 @@ pub struct BitcoinAddressNetworkMismatch { pub struct Arguments { pub testnet: bool, pub json: bool, - pub disable_timestamp: bool, pub config_path: PathBuf, pub env_config: env::Config, pub cmd: Command, @@ -199,6 +201,11 @@ pub enum Command { only_unfinished: bool, }, Config, + Logs { + logs_dir: Option, + swap_id: Option, + redact: bool, + }, WithdrawBtc { amount: Option, address: Address, @@ -270,6 +277,25 @@ pub enum RawCommand { )] resume_only: bool, }, + #[structopt(about = "Prints all logging messages issued in the past.")] + Logs { + #[structopt( + short = "d", + help = "Print the logs from this directory instead of the default one." + )] + logs_dir: Option, + #[structopt( + help = "Redact swap-ids, Bitcoin and Monero addresses.", + long = "redact" + )] + redact: bool, + #[structopt( + long = "swap-id", + help = "Filter for logs concerning this swap.", + long_help = "This checks whether each logging message contains the swap id. Some messages might be skipped when they don't contain the swap id even though they're relevant." + )] + swap_id: Option, + }, #[structopt(about = "Prints swap-id and the state of each swap ever made.")] History { #[structopt( @@ -374,7 +400,6 @@ mod tests { let expected_args = Arguments { testnet: false, json: false, - disable_timestamp: false, config_path: default_mainnet_conf_path, env_config: mainnet_env_config, cmd: Command::Start { resume_only: false }, @@ -392,7 +417,6 @@ mod tests { let expected_args = Arguments { testnet: false, json: false, - disable_timestamp: false, config_path: default_mainnet_conf_path, env_config: mainnet_env_config, cmd: Command::History { @@ -412,7 +436,6 @@ mod tests { let expected_args = Arguments { testnet: false, json: false, - disable_timestamp: false, config_path: default_mainnet_conf_path, env_config: mainnet_env_config, cmd: Command::Balance, @@ -434,7 +457,6 @@ mod tests { let expected_args = Arguments { testnet: false, json: false, - disable_timestamp: false, config_path: default_mainnet_conf_path, env_config: mainnet_env_config, cmd: Command::WithdrawBtc { @@ -461,7 +483,6 @@ mod tests { let expected_args = Arguments { testnet: false, json: false, - disable_timestamp: false, config_path: default_mainnet_conf_path, env_config: mainnet_env_config, cmd: Command::Cancel { @@ -487,7 +508,6 @@ mod tests { let expected_args = Arguments { testnet: false, json: false, - disable_timestamp: false, config_path: default_mainnet_conf_path, env_config: mainnet_env_config, cmd: Command::Refund { @@ -513,7 +533,6 @@ mod tests { let expected_args = Arguments { testnet: false, json: false, - disable_timestamp: false, config_path: default_mainnet_conf_path, env_config: mainnet_env_config, cmd: Command::Punish { @@ -539,7 +558,6 @@ mod tests { let expected_args = Arguments { testnet: false, json: false, - disable_timestamp: false, config_path: default_mainnet_conf_path, env_config: mainnet_env_config, cmd: Command::SafelyAbort { @@ -559,7 +577,6 @@ mod tests { let expected_args = Arguments { testnet: true, json: false, - disable_timestamp: false, config_path: default_testnet_conf_path, env_config: testnet_env_config, cmd: Command::Start { resume_only: false }, @@ -577,7 +594,6 @@ mod tests { let expected_args = Arguments { testnet: true, json: false, - disable_timestamp: false, config_path: default_testnet_conf_path, env_config: testnet_env_config, cmd: Command::History { @@ -597,7 +613,6 @@ mod tests { let expected_args = Arguments { testnet: true, json: false, - disable_timestamp: false, config_path: default_testnet_conf_path, env_config: testnet_env_config, cmd: Command::Balance, @@ -621,7 +636,6 @@ mod tests { let expected_args = Arguments { testnet: true, json: false, - disable_timestamp: false, config_path: default_testnet_conf_path, env_config: testnet_env_config, cmd: Command::WithdrawBtc { @@ -648,7 +662,6 @@ mod tests { let expected_args = Arguments { testnet: true, json: false, - disable_timestamp: false, config_path: default_testnet_conf_path, env_config: testnet_env_config, cmd: Command::Cancel { @@ -675,7 +688,6 @@ mod tests { let expected_args = Arguments { testnet: true, json: false, - disable_timestamp: false, config_path: default_testnet_conf_path, env_config: testnet_env_config, cmd: Command::Refund { @@ -702,7 +714,6 @@ mod tests { let expected_args = Arguments { testnet: true, json: false, - disable_timestamp: false, config_path: default_testnet_conf_path, env_config: testnet_env_config, cmd: Command::Punish { @@ -729,7 +740,6 @@ mod tests { let expected_args = Arguments { testnet: true, json: false, - disable_timestamp: false, config_path: default_testnet_conf_path, env_config: testnet_env_config, cmd: Command::SafelyAbort { @@ -749,7 +759,6 @@ mod tests { let expected_args = Arguments { testnet: false, json: false, - disable_timestamp: true, config_path: default_mainnet_conf_path, env_config: mainnet_env_config, cmd: Command::Start { resume_only: false }, diff --git a/swap/src/asb/tracing.rs b/swap/src/asb/tracing.rs deleted file mode 100644 index c21c1e70..00000000 --- a/swap/src/asb/tracing.rs +++ /dev/null @@ -1,30 +0,0 @@ -use anyhow::Result; -use tracing_subscriber::filter::LevelFilter; -use tracing_subscriber::fmt::time::UtcTime; -use tracing_subscriber::FmtSubscriber; - -pub fn init(level: LevelFilter, json_format: bool, timestamp: bool) -> Result<()> { - if level == LevelFilter::OFF { - return Ok(()); - } - - let is_terminal = atty::is(atty::Stream::Stderr); - - let builder = FmtSubscriber::builder() - .with_env_filter(format!("asb={},swap={}", level, level)) - .with_writer(std::io::stderr) - .with_ansi(is_terminal) - .with_timer(UtcTime::rfc_3339()) - .with_target(false); - - match (json_format, timestamp) { - (true, true) => builder.json().init(), - (true, false) => builder.json().without_time().init(), - (false, true) => builder.init(), - (false, false) => builder.without_time().init(), - } - - tracing::info!(%level, "Initialized tracing"); - - Ok(()) -} diff --git a/swap/src/bin/asb.rs b/swap/src/bin/asb.rs index 66630b88..3a0d2dd4 100644 --- a/swap/src/bin/asb.rs +++ b/swap/src/bin/asb.rs @@ -31,7 +31,8 @@ use swap::asb::config::{ initial_setup, query_user_for_initial_config, read_config, Config, ConfigNotInitialized, }; use swap::asb::{cancel, punish, redeem, refund, safely_abort, EventLoop, Finality, KrakenRate}; -use swap::common::check_latest_version; +use swap::common::tracing_util::Format; +use swap::common::{self, check_latest_version, get_logs}; use swap::database::{open_db, AccessMode}; use swap::network::rendezvous::XmrBtcNamespace; use swap::network::swarm; @@ -40,44 +41,40 @@ use swap::protocol::alice::{run, AliceState}; use swap::protocol::State; use swap::seed::Seed; use swap::tor::AuthenticatedClient; -use swap::{asb, bitcoin, kraken, monero, tor}; +use swap::{bitcoin, kraken, monero, tor}; use tracing_subscriber::filter::LevelFilter; const DEFAULT_WALLET_NAME: &str = "asb-wallet"; #[tokio::main] async fn main() -> Result<()> { + // parse cli arguments let Arguments { testnet, json, - disable_timestamp, config_path, env_config, cmd, } = match parse_args(env::args_os()) { Ok(args) => args, Err(e) => { + // make sure to display the clap error message it exists if let Some(clap_err) = e.downcast_ref::() { - match clap_err.kind { - ErrorKind::HelpDisplayed | ErrorKind::VersionDisplayed => { - println!("{}", clap_err.message); - std::process::exit(0); - } - _ => { - bail!(e); - } + if let ErrorKind::HelpDisplayed | ErrorKind::VersionDisplayed = clap_err.kind { + println!("{}", clap_err.message); + std::process::exit(0); } } bail!(e); } }; + // warn if we're not on the latest version if let Err(e) = check_latest_version(env!("CARGO_PKG_VERSION")).await { eprintln!("{}", e); } - asb::tracing::init(LevelFilter::DEBUG, json, !disable_timestamp).expect("initialize tracing"); - + // read config from the specified path let config = match read_config(config_path.clone())? { Ok(config) => config, Err(ConfigNotInitialized {}) => { @@ -86,6 +83,12 @@ async fn main() -> Result<()> { } }; + // initialize tracing + let format = if json { Format::Json } else { Format::Raw }; + let log_dir = config.data.dir.join("logs"); + common::tracing_util::init(LevelFilter::DEBUG, format, log_dir).expect("initialize tracing"); + + // check for conflicting env / config values if config.monero.network != env_config.monero_network { bail!(format!( "Expected monero network in config file to be {:?} but was {:?}", @@ -112,6 +115,7 @@ async fn main() -> Result<()> { rendezvous_addrs.sort(); rendezvous_addrs.dedup(); let new_len = rendezvous_addrs.len(); + if new_len < prev_len { tracing::warn!( "`rendezvous_point` config has {} duplicate entries, they are being ignored.", @@ -119,9 +123,12 @@ async fn main() -> Result<()> { ); } + // initialize monero wallet let monero_wallet = init_monero_wallet(&config, env_config).await?; let monero_address = monero_wallet.get_main_address(); tracing::info!(%monero_address, "Monero wallet address"); + + // check monero balance let monero = monero_wallet.get_balance().await?; match (monero.balance, monero.unlocked_balance) { (0, _) => { @@ -144,6 +151,7 @@ async fn main() -> Result<()> { } } + // init bitcoin wallet let bitcoin_wallet = init_bitcoin_wallet(&config, &seed, env_config).await?; let bitcoin_balance = bitcoin_wallet.balance().await?; tracing::info!(%bitcoin_balance, "Bitcoin wallet balance"); @@ -314,6 +322,19 @@ async fn main() -> Result<()> { let config_json = serde_json::to_string_pretty(&config)?; println!("{}", config_json); } + Command::Logs { + logs_dir, + swap_id, + redact, + } => { + let dir = logs_dir.unwrap_or(config.data.dir.join("logs")); + + let log_messages = get_logs(dir, swap_id, redact).await?; + + for msg in log_messages { + println!("{msg}"); + } + } Command::WithdrawBtc { amount, address } => { let bitcoin_wallet = init_bitcoin_wallet(&config, &seed, env_config).await?; diff --git a/swap/src/cli.rs b/swap/src/cli.rs index f0faf146..6085eca0 100644 --- a/swap/src/cli.rs +++ b/swap/src/cli.rs @@ -3,7 +3,6 @@ pub mod cancel_and_refund; pub mod command; mod event_loop; mod list_sellers; -pub mod tracing; pub mod transport; pub use behaviour::{Behaviour, OutEvent}; diff --git a/swap/src/cli/command.rs b/swap/src/cli/command.rs index 6c460f82..acce7a50 100644 --- a/swap/src/cli/command.rs +++ b/swap/src/cli/command.rs @@ -105,6 +105,22 @@ where .await?; (context, request) } + CliCommand::Logs { + logs_dir, + redact, + swap_id, + } => { + let request = Request::new(Method::Logs { + logs_dir, + redact, + swap_id, + }); + let context = + Context::build(None, None, None, data, is_testnet, debug, json, None, false) + .await?; + + (context, request) + } CliCommand::Config => { let request = Request::new(Method::Config); @@ -341,6 +357,25 @@ enum CliCommand { }, /// Show a list of past, ongoing and completed swaps History, + /// Output all logging messages that have been issued. + Logs { + #[structopt( + short = "d", + help = "Print the logs from this directory instead of the default one." + )] + logs_dir: Option, + #[structopt( + help = "Redact swap-ids, Bitcoin and Monero addresses.", + long = "redact" + )] + redact: bool, + #[structopt( + long = "swap-id", + help = "Filter for logs concerning this swap.", + long_help = "This checks whether each logging message contains the swap id. Some messages might be skipped when they don't contain the swap id even though they're relevant." + )] + swap_id: Option, + }, #[structopt(about = "Prints the current config")] Config, #[structopt(about = "Allows withdrawing BTC from the internal Bitcoin wallet.")] diff --git a/swap/src/cli/tracing.rs b/swap/src/cli/tracing.rs deleted file mode 100644 index 6b6de60f..00000000 --- a/swap/src/cli/tracing.rs +++ /dev/null @@ -1,112 +0,0 @@ -use anyhow::Result; -use std::path::Path; -use time::format_description::well_known::Rfc3339; -use tracing::subscriber::set_global_default; -use tracing::{Event, Level, Subscriber}; -use tracing_subscriber::fmt::format::{DefaultFields, Format, JsonFields}; -use tracing_subscriber::fmt::time::UtcTime; -use tracing_subscriber::layer::{Context, SubscriberExt}; -use tracing_subscriber::{fmt, EnvFilter, Layer, Registry}; - -pub fn init(debug: bool, json: bool, dir: impl AsRef) -> Result<()> { - let level_filter = EnvFilter::try_new("swap=debug")?; - let registry = Registry::default().with(level_filter); - - let appender = tracing_appender::rolling::never(dir.as_ref(), "swap-all.log"); - - let file_logger = registry.with( - fmt::layer() - .with_ansi(false) - .with_target(false) - .json() - .with_writer(appender), - ); - - if json && debug { - set_global_default(file_logger.with(debug_json_terminal_printer()))?; - } else if json && !debug { - set_global_default(file_logger.with(info_json_terminal_printer()))?; - } else if !json && debug { - set_global_default(file_logger.with(debug_terminal_printer()))?; - } else { - set_global_default(file_logger.with(info_terminal_printer()))?; - } - - tracing::info!("Logging initialized to {}", dir.as_ref().display()); - Ok(()) -} - -pub struct StdErrPrinter { - inner: L, - level: Level, -} - -type StdErrLayer = - fmt::Layer, fn() -> std::io::Stderr>; - -type StdErrJsonLayer = - fmt::Layer, 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(UtcTime::rfc_3339()) - .with_writer(std::io::stderr), - level: Level::DEBUG, - } -} - -fn debug_json_terminal_printer() -> StdErrPrinter>> { - let is_terminal = atty::is(atty::Stream::Stderr); - StdErrPrinter { - inner: fmt::layer() - .with_ansi(is_terminal) - .with_target(false) - .with_timer(UtcTime::rfc_3339()) - .json() - .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, - } -} - -fn info_json_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() - .json() - .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); - } - } -} diff --git a/swap/src/common.rs b/swap/src/common.rs deleted file mode 100644 index 98b9b99d..00000000 --- a/swap/src/common.rs +++ /dev/null @@ -1,56 +0,0 @@ -use anyhow::anyhow; - -const LATEST_RELEASE_URL: &str = "https://github.com/comit-network/xmr-btc-swap/releases/latest"; - -#[derive(Clone, Debug, PartialEq, Eq)] -pub enum Version { - Current, - Available, -} - -/// Check the latest release from GitHub API. -pub async fn check_latest_version(current_version: &str) -> anyhow::Result { - let response = reqwest::get(LATEST_RELEASE_URL).await?; - let e = "Failed to get latest release."; - let download_url = response.url(); - let segments = download_url.path_segments().ok_or_else(|| anyhow!(e))?; - let latest_version = segments.last().ok_or_else(|| anyhow!(e))?; - - let result = if is_latest_version(current_version, latest_version) { - Version::Current - } else { - tracing::warn!(%current_version, %latest_version, %download_url, - "You are not on the latest version", - ); - Version::Available - }; - - Ok(result) -} - -// todo: naive implementation can be improved using semver -fn is_latest_version(current: &str, latest: &str) -> bool { - current == latest -} - -#[cfg(test)] -mod test { - use super::*; - - #[test] - fn it_compares_versions() { - assert!(is_latest_version("0.10.2", "0.10.2")); - assert!(!is_latest_version("0.10.2", "0.10.3")); - assert!(!is_latest_version("0.10.2", "0.11.0")); - } - - #[tokio::test] - #[ignore = "For local testing, makes http requests to github."] - async fn it_compares_with_github() { - let result = check_latest_version("0.11.0").await.unwrap(); - assert_eq!(result, Version::Available); - - let result = check_latest_version("0.11.1").await.unwrap(); - assert_eq!(result, Version::Current); - } -} diff --git a/swap/src/common/mod.rs b/swap/src/common/mod.rs new file mode 100644 index 00000000..bae1c0f4 --- /dev/null +++ b/swap/src/common/mod.rs @@ -0,0 +1,221 @@ +pub mod tracing_util; + +use std::{collections::HashMap, path::PathBuf}; + +use anyhow::anyhow; +use tokio::{ + fs::{read_dir, File}, + io::{AsyncBufReadExt, BufReader}, +}; +use uuid::Uuid; + +const LATEST_RELEASE_URL: &str = "https://github.com/comit-network/xmr-btc-swap/releases/latest"; + +#[derive(Clone, Debug, PartialEq, Eq)] +pub enum Version { + Current, + Available, +} + +/// Check the latest release from GitHub API. +pub async fn check_latest_version(current_version: &str) -> anyhow::Result { + let response = reqwest::get(LATEST_RELEASE_URL).await?; + let e = "Failed to get latest release."; + let download_url = response.url(); + let segments = download_url.path_segments().ok_or_else(|| anyhow!(e))?; + let latest_version = segments.last().ok_or_else(|| anyhow!(e))?; + + let result = if is_latest_version(current_version, latest_version) { + Version::Current + } else { + tracing::warn!(%current_version, %latest_version, %download_url, + "You are not on the latest version", + ); + Version::Available + }; + + Ok(result) +} + +// todo: naive implementation can be improved using semver +fn is_latest_version(current: &str, latest: &str) -> bool { + current == latest +} + +/// helper macro for [`redact`]... eldrich sorcery +/// the macro does in essence the following: +/// 1. create a static regex automaton for the pattern +/// 2. find all matching patterns using regex +/// 3. create a placeholder for each distinct matching pattern +/// 4. add the placeholder to the hashmap +macro_rules! regex_find_placeholders { + ($pattern:expr, $create_placeholder:expr, $replacements:expr, $input:expr) => {{ + // compile the regex pattern + static REGEX: once_cell::sync::Lazy = once_cell::sync::Lazy::new(|| { + tracing::debug!("initializing regex"); + regex::Regex::new($pattern).expect("invalid regex pattern") + }); + + // keep count of count patterns to generate distinct placeholders + let mut counter: usize = 0; + + // for every matched address check whether we already found it + // and if we didn't, generate a placeholder for it + for address in REGEX.find_iter($input) { + if !$replacements.contains_key(address.as_str()) { + #[allow(clippy::redundant_closure_call)] + $replacements.insert(address.as_str().to_owned(), $create_placeholder(counter)); + counter += 1; + } + } + }}; +} + +/// Print the logs from the specified logs or from the default location +/// to the specified path or the terminal. +/// +/// If specified, filter by swap id or redact addresses. +pub async fn get_logs( + logs_dir: PathBuf, + swap_id: Option, + redact_addresses: bool, +) -> anyhow::Result> { + tracing::debug!("reading logfiles from {}", logs_dir.display()); + + // get all files in the directory + let mut log_files = read_dir(&logs_dir).await?; + + let mut log_messages = Vec::new(); + // when we redact we need to store the placeholder + let mut placeholders = HashMap::new(); + + // print all lines from every log file. TODO: sort files by date? + while let Some(entry) = log_files.next_entry().await? { + // get the file path + let file_path = entry.path(); + + // filter for .log files + let file_name = file_path + .file_name() + .and_then(|name| name.to_str()) + .unwrap_or(""); + + if !file_name.ends_with(".log") { + continue; + } + + // use BufReader to stay easy on memory and then read line by line + let buf_reader = BufReader::new(File::open(&file_path).await?); + let mut lines = buf_reader.lines(); + + // print each line, redacted if the flag is set + while let Some(line) = lines.next_line().await? { + // if we should filter by swap id, check if the line contains it + if let Some(swap_id) = swap_id { + // we only want lines which contain the swap id + if !line.contains(&swap_id.to_string()) { + continue; + } + } + + // redact if necessary + let line = if redact_addresses { + redact_with(&line, &mut placeholders) + } else { + line + }; + // save redacted message + log_messages.push(line); + } + } + + Ok(log_messages) +} + +/// Redact logs, etc. by replacing Bitcoin and Monero addresses +/// with generic placeholders. +/// +/// # Example +/// ```rust +/// use swap::common::redact; +/// +/// let redacted = redact("a9165a1e-d26d-4b56-bf6d-ca9658825c44"); +/// assert_eq!(redacted, ""); +/// ``` +pub fn redact(input: &str) -> String { + let mut replacements = HashMap::new(); + redact_with(input, &mut replacements) +} + +/// Same as [`redact`] but retrieves palceholders from and stores them +/// in a specified hashmap. +pub fn redact_with(input: &str, replacements: &mut HashMap) -> String { + // TODO: verify regex patterns + const MONERO_ADDR_REGEX: &str = r#"[48][1-9A-HJ-NP-Za-km-z]{94}"#; + const BITCOIN_ADDR_REGEX: &str = r#"\b[13][a-km-zA-HJ-NP-Z1-9]{25,34}\b"#; + // Both XMR and BTC transactions have + // a 64 bit hex id so they aren't distinguishible + const TX_ID_REGEX: &str = r#"\b[a-fA-F0-9]{64}\b"#; + const SWAP_ID_REGEX: &str = + r#"\b[a-f0-9]{8}-[a-f0-9]{4}-4[a-f0-9]{3}-[89aAbB][a-f0-9]{3}-[a-f0-9]{12}\b"#; + + // use the macro to find all addresses and generate placeholders + // has to be a macro in order to create the regex automata only once. + regex_find_placeholders!( + MONERO_ADDR_REGEX, + |count| format!(""), + replacements, + input + ); + regex_find_placeholders!( + BITCOIN_ADDR_REGEX, + |count| format!(""), + replacements, + input + ); + regex_find_placeholders!( + TX_ID_REGEX, + |count| format!(""), + replacements, + input + ); + regex_find_placeholders!( + SWAP_ID_REGEX, + |count| format!(""), + replacements, + input + ); + + // allocate string variable to operate on + let mut redacted = input.to_owned(); + + // Finally we go through the input string and replace each occurance of an + // address we want to redact with the corresponding placeholder + for (address, placeholder) in replacements.iter() { + redacted = redacted.replace(address, placeholder); + } + + redacted +} + +#[cfg(test)] +mod test { + use super::*; + + #[test] + fn it_compares_versions() { + assert!(is_latest_version("0.10.2", "0.10.2")); + assert!(!is_latest_version("0.10.2", "0.10.3")); + assert!(!is_latest_version("0.10.2", "0.11.0")); + } + + #[tokio::test] + #[ignore = "For local testing, makes http requests to github."] + async fn it_compares_with_github() { + let result = check_latest_version("0.11.0").await.unwrap(); + assert_eq!(result, Version::Available); + + let result = check_latest_version("0.11.1").await.unwrap(); + assert_eq!(result, Version::Current); + } +} diff --git a/swap/src/common/tracing_util.rs b/swap/src/common/tracing_util.rs new file mode 100644 index 00000000..191c43bf --- /dev/null +++ b/swap/src/common/tracing_util.rs @@ -0,0 +1,64 @@ +use std::path::Path; +use std::str::FromStr; + +use anyhow::Result; +use tracing_subscriber::filter::{Directive, LevelFilter}; +use tracing_subscriber::fmt::time::UtcTime; +use tracing_subscriber::layer::SubscriberExt; +use tracing_subscriber::util::SubscriberInitExt; +use tracing_subscriber::{fmt, EnvFilter, Layer}; + +/// Output formats for logging messages. +pub enum Format { + /// Standard, human readable format. + Raw, + /// JSON, machine readable format. + Json, +} + +/// Initialize tracing and enable logging messages according to these options. +/// Besides printing to `stdout`, this will append to a log file. +/// Said file will contain JSON-formatted logs of all levels, +/// disregarding the arguments to this function. +pub fn init(level_filter: LevelFilter, format: Format, dir: impl AsRef) -> Result<()> { + let env_filter = EnvFilter::from_default_env() + .add_directive(Directive::from_str(&format!("asb={}", &level_filter))?) + .add_directive(Directive::from_str(&format!("swap={}", &level_filter))?); + + // file logger will always write in JSON format and with timestamps + let file_appender = tracing_appender::rolling::never(&dir, "swap-all.log"); + + let file_layer = fmt::layer() + .with_writer(file_appender) + .with_ansi(false) + .with_timer(UtcTime::rfc_3339()) + .with_target(false) + .json() + .with_filter(env_filter); + + // terminal logger + let is_terminal = atty::is(atty::Stream::Stderr); + let terminal_layer = fmt::layer() + .with_writer(std::io::stdout) + .with_ansi(is_terminal) + .with_timer(UtcTime::rfc_3339()) + .with_target(false); + + // combine the layers and start logging, format with json if specified + if let Format::Json = format { + tracing_subscriber::registry() + .with(file_layer) + .with(terminal_layer.json().with_filter(level_filter)) + .init(); + } else { + tracing_subscriber::registry() + .with(file_layer) + .with(terminal_layer.with_filter(level_filter)) + .init(); + } + + // now we can use the tracing macros to log messages + tracing::info!(%level_filter, logs_dir=%dir.as_ref().display(), "Initialized tracing"); + + Ok(()) +} diff --git a/swap/src/database/sqlite.rs b/swap/src/database/sqlite.rs index eb013f66..ce455b6c 100644 --- a/swap/src/database/sqlite.rs +++ b/swap/src/database/sqlite.rs @@ -5,7 +5,7 @@ use anyhow::{anyhow, Context, Result}; use async_trait::async_trait; use libp2p::{Multiaddr, PeerId}; use sqlx::sqlite::{Sqlite, SqliteConnectOptions}; -use sqlx::{Pool, SqlitePool}; +use sqlx::{ConnectOptions, Pool, SqlitePool}; use std::collections::HashMap; use std::path::Path; use std::str::FromStr; @@ -26,7 +26,8 @@ impl SqliteDatabase { let read_only = matches!(access_mode, AccessMode::ReadOnly); let path_str = format!("sqlite:{}", path.as_ref().display()); - let options = SqliteConnectOptions::from_str(&path_str)?.read_only(read_only); + let mut options = SqliteConnectOptions::from_str(&path_str)?.read_only(read_only); + options.disable_statement_logging(); let pool = SqlitePool::connect_with(options).await?; let mut sqlite = Self { pool }; diff --git a/swap/src/rpc/methods.rs b/swap/src/rpc/methods.rs index f804e085..dd3d9a62 100644 --- a/swap/src/rpc/methods.rs +++ b/swap/src/rpc/methods.rs @@ -7,7 +7,9 @@ use anyhow::Result; use jsonrpsee::server::RpcModule; use jsonrpsee::types::Params; use libp2p::core::Multiaddr; +use serde::Deserialize; use std::collections::HashMap; +use std::path::PathBuf; use std::str::FromStr; use std::sync::Arc; use uuid::Uuid; @@ -48,8 +50,30 @@ pub fn register_modules(context: Arc) -> Result> execute_request(params_raw, Method::Balance { force_refresh }, &context).await })?; - module.register_async_method("get_history", |params, context| async move { - execute_request(params, Method::History, &context).await + module.register_async_method("get_history", |params_raw, context| async move { + execute_request(params_raw, Method::History, &context).await + })?; + + module.register_async_method("get_logs", |params_raw, context| async move { + #[derive(Debug, Clone, Deserialize)] + struct Params { + swap_id: Option, + logs_dir: Option, + redact: bool, + } + + let params: Params = params_raw.parse()?; + + execute_request( + params_raw, + Method::Logs { + swap_id: params.swap_id, + logs_dir: params.logs_dir, + redact: params.redact, + }, + &context, + ) + .await })?; module.register_async_method("get_raw_states", |params, context| async move { diff --git a/swap/src/seed.rs b/swap/src/seed.rs index aa363905..a17a7964 100644 --- a/swap/src/seed.rs +++ b/swap/src/seed.rs @@ -1,9 +1,9 @@ use crate::fs::ensure_directory_exists; -use ::bitcoin::secp256k1::constants::SECRET_KEY_SIZE; -use ::bitcoin::secp256k1::{self, SecretKey}; use anyhow::{Context, Result}; use bdk::bitcoin::util::bip32::ExtendedPrivKey; use bitcoin::hashes::{sha256, Hash, HashEngine}; +use bitcoin::secp256k1::constants::SECRET_KEY_SIZE; +use bitcoin::secp256k1::{self, SecretKey}; use libp2p::identity; use pem::{encode, Pem}; use rand::prelude::*;