From 0029f04fce6beba29e60b2c227d51bcf1ba15545 Mon Sep 17 00:00:00 2001 From: Antoine Riard Date: Wed, 25 Jul 2018 02:34:51 +0000 Subject: [PATCH] Logging interface Implement error, warn, info, debug and trace macros, internally calling an instance of Logger, and passing it to every main structures Build-time or client-side filtering. Issue #54 --- Cargo.toml | 6 + fuzz/fuzz_targets/channel_target.rs | 12 +- fuzz/fuzz_targets/full_stack_target.rs | 14 ++- fuzz/fuzz_targets/router_target.rs | 11 +- fuzz/fuzz_targets/utils/mod.rs | 1 + fuzz/fuzz_targets/utils/test_logger.rs | 23 ++++ src/chain/chaininterface.rs | 11 +- src/lib.rs | 3 +- src/ln/channel.rs | 21 +++- src/ln/channelmanager.rs | 26 ++-- src/ln/peer_handler.rs | 13 +- src/ln/router.rs | 14 ++- src/util/logger.rs | 168 +++++++++++++++++++++++++ src/util/macro_logger.rs | 42 +++++++ src/util/mod.rs | 5 + src/util/test_utils.rs | 24 ++++ 16 files changed, 362 insertions(+), 32 deletions(-) create mode 100644 fuzz/fuzz_targets/utils/mod.rs create mode 100644 fuzz/fuzz_targets/utils/test_logger.rs create mode 100644 src/util/logger.rs create mode 100644 src/util/macro_logger.rs diff --git a/Cargo.toml b/Cargo.toml index 69c6f44b7..088763ccb 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -15,6 +15,12 @@ build = "build.rs" # Supports tracking channels with a non-bitcoin chain hashes. Currently enables all kinds of fun DoS attacks. non_bitcoin_chain_hash_routing = [] fuzztarget = ["secp256k1/fuzztarget", "bitcoin/fuzztarget"] +# Unlog messages superior at targeted level. +max_level_off = [] +max_level_error = [] +max_level_warn = [] +max_level_info = [] +max_level_debug = [] [dependencies] bitcoin = "0.13" diff --git a/fuzz/fuzz_targets/channel_target.rs b/fuzz/fuzz_targets/channel_target.rs index 683faf0ed..d5c483f77 100644 --- a/fuzz/fuzz_targets/channel_target.rs +++ b/fuzz/fuzz_targets/channel_target.rs @@ -14,11 +14,17 @@ use lightning::ln::msgs::{MsgDecodable, ErrorAction}; use lightning::chain::chaininterface::{FeeEstimator, ConfirmationTarget}; use lightning::chain::transaction::OutPoint; use lightning::util::reset_rng_state; +use lightning::util::logger::Logger; + +mod utils; + +use utils::test_logger; use secp256k1::key::{PublicKey, SecretKey}; use secp256k1::Secp256k1; use std::sync::atomic::{AtomicUsize,Ordering}; +use std::sync::Arc; #[inline] pub fn slice_to_be16(v: &[u8]) -> u16 { @@ -101,6 +107,8 @@ pub fn do_test(data: &[u8]) { input: &input, }; + let logger: Arc = Arc::new(test_logger::TestLogger::new()); + macro_rules! get_slice { ($len: expr) => { match input.get_slice($len as usize) { @@ -191,7 +199,7 @@ pub fn do_test(data: &[u8]) { let mut channel = if get_slice!(1)[0] != 0 { let chan_value = slice_to_be24(get_slice!(3)); - let mut chan = Channel::new_outbound(&fee_est, chan_keys!(), their_pubkey, chan_value, get_slice!(1)[0] == 0, slice_to_be64(get_slice!(8))); + let mut chan = Channel::new_outbound(&fee_est, chan_keys!(), their_pubkey, chan_value, get_slice!(1)[0] == 0, slice_to_be64(get_slice!(8)), Arc::clone(&logger)); chan.get_open_channel(Sha256dHash::from(get_slice!(32)), &fee_est).unwrap(); let accept_chan = if get_slice!(1)[0] == 0 { decode_msg_with_len16!(msgs::AcceptChannel, 270, 1) @@ -213,7 +221,7 @@ pub fn do_test(data: &[u8]) { } else { decode_msg!(msgs::OpenChannel, 2*32+6*8+4+2*2+6*33+1) }; - let mut chan = match Channel::new_from_req(&fee_est, chan_keys!(), their_pubkey, &open_chan, slice_to_be64(get_slice!(8)), false, get_slice!(1)[0] == 0) { + let mut chan = match Channel::new_from_req(&fee_est, chan_keys!(), their_pubkey, &open_chan, slice_to_be64(get_slice!(8)), false, get_slice!(1)[0] == 0, Arc::clone(&logger)) { Ok(chan) => chan, Err(_) => return, }; diff --git a/fuzz/fuzz_targets/full_stack_target.rs b/fuzz/fuzz_targets/full_stack_target.rs index cf84701d4..8f7ec2df0 100644 --- a/fuzz/fuzz_targets/full_stack_target.rs +++ b/fuzz/fuzz_targets/full_stack_target.rs @@ -21,6 +21,11 @@ use lightning::ln::peer_handler::{MessageHandler,PeerManager,SocketDescriptor}; use lightning::ln::router::Router; use lightning::util::events::{EventsProvider,Event}; use lightning::util::reset_rng_state; +use lightning::util::logger::Logger; + +mod utils; + +use utils::test_logger; use secp256k1::key::{PublicKey,SecretKey}; use secp256k1::Secp256k1; @@ -169,18 +174,19 @@ pub fn do_test(data: &[u8]) { Err(_) => return, }; + let logger: Arc = Arc::new(test_logger::TestLogger::new()); let monitor = Arc::new(TestChannelMonitor{}); - let watch = Arc::new(ChainWatchInterfaceUtil::new()); + let watch = Arc::new(ChainWatchInterfaceUtil::new(Arc::clone(&logger))); let broadcast = Arc::new(TestBroadcaster{}); - let channelmanager = ChannelManager::new(our_network_key, slice_to_be32(get_slice!(4)), get_slice!(1)[0] != 0, Network::Bitcoin, fee_est.clone(), monitor.clone(), watch.clone(), broadcast.clone()).unwrap(); - let router = Arc::new(Router::new(PublicKey::from_secret_key(&secp_ctx, &our_network_key).unwrap())); + let channelmanager = ChannelManager::new(our_network_key, slice_to_be32(get_slice!(4)), get_slice!(1)[0] != 0, Network::Bitcoin, fee_est.clone(), monitor.clone(), watch.clone(), broadcast.clone(), Arc::clone(&logger)).unwrap(); + let router = Arc::new(Router::new(PublicKey::from_secret_key(&secp_ctx, &our_network_key).unwrap(), Arc::clone(&logger))); let peers = RefCell::new([false; 256]); let handler = PeerManager::new(MessageHandler { chan_handler: channelmanager.clone(), route_handler: router.clone(), - }, our_network_key); + }, our_network_key, Arc::clone(&logger)); let mut should_forward = false; let mut payments_received = Vec::new(); diff --git a/fuzz/fuzz_targets/router_target.rs b/fuzz/fuzz_targets/router_target.rs index ed4737221..f9c8d2ba2 100644 --- a/fuzz/fuzz_targets/router_target.rs +++ b/fuzz/fuzz_targets/router_target.rs @@ -7,10 +7,17 @@ use lightning::ln::msgs; use lightning::ln::msgs::{MsgDecodable, RoutingMessageHandler}; use lightning::ln::router::{Router, RouteHint}; use lightning::util::reset_rng_state; +use lightning::util::logger::Logger; use secp256k1::key::PublicKey; use secp256k1::Secp256k1; +mod utils; + +use utils::test_logger; + +use std::sync::Arc; + #[inline] pub fn slice_to_be16(v: &[u8]) -> u16 { ((v[0] as u16) << 8*1) | @@ -98,8 +105,10 @@ pub fn do_test(data: &[u8]) { } } + let logger: Arc = Arc::new(test_logger::TestLogger::new()); + let our_pubkey = get_pubkey!(); - let router = Router::new(our_pubkey.clone()); + let router = Router::new(our_pubkey.clone(), Arc::clone(&logger)); loop { match get_slice!(1)[0] { diff --git a/fuzz/fuzz_targets/utils/mod.rs b/fuzz/fuzz_targets/utils/mod.rs new file mode 100644 index 000000000..a7d7c32d5 --- /dev/null +++ b/fuzz/fuzz_targets/utils/mod.rs @@ -0,0 +1 @@ +pub(crate) mod test_logger; diff --git a/fuzz/fuzz_targets/utils/test_logger.rs b/fuzz/fuzz_targets/utils/test_logger.rs new file mode 100644 index 000000000..4446897be --- /dev/null +++ b/fuzz/fuzz_targets/utils/test_logger.rs @@ -0,0 +1,23 @@ +use lightning::util::logger::{Logger, Level, Record}; + +pub struct TestLogger { + level: Level, +} + +impl TestLogger { + pub fn new() -> TestLogger { + TestLogger { + level: Level::Off, + } + } + pub fn enable(&mut self, level: Level) { + self.level = level; + } +} + +impl Logger for TestLogger { + fn log(&self, record: &Record) { + #[cfg(any(test, not(feature = "fuzztarget")))] + println!("{:<5} [{} : {}, {}] {}", record.level.to_string(), record.module_path, record.file, record.line, record.args); + } +} diff --git a/src/chain/chaininterface.rs b/src/chain/chaininterface.rs index 7e9e9aeff..e08c8cdbd 100644 --- a/src/chain/chaininterface.rs +++ b/src/chain/chaininterface.rs @@ -2,7 +2,8 @@ use bitcoin::blockdata::block::{Block, BlockHeader}; use bitcoin::blockdata::transaction::Transaction; use bitcoin::blockdata::script::Script; use bitcoin::util::hash::Sha256dHash; -use std::sync::{Mutex,Weak,MutexGuard}; +use util::logger::Logger; +use std::sync::{Mutex,Weak,MutexGuard,Arc}; use std::sync::atomic::{AtomicUsize, Ordering}; /// An interface to request notification of certain scripts as they appear the @@ -70,7 +71,8 @@ pub trait FeeEstimator: Sync + Send { pub struct ChainWatchInterfaceUtil { watched: Mutex<(Vec