Skip to content

Commit

Permalink
fix: add logging module and validate log entries
Browse files Browse the repository at this point in the history
Additionally addresses minor issues related to:
- Default impl
- Verbose TestLogWriter enum
- MockLogFacadeLogger and node_config rename
  • Loading branch information
enigbe committed Feb 20, 2025
1 parent 656a841 commit 30bee82
Show file tree
Hide file tree
Showing 3 changed files with 179 additions and 134 deletions.
148 changes: 148 additions & 0 deletions tests/common/logging.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,148 @@
use chrono::Utc;
use ldk_node::logger::{LogLevel, LogRecord, LogWriter};
use log::{
Level as LogFacadeLevel, LevelFilter as LogFacadeLevelFilter, Log as LogFacadeLog,
Record as LogFacadeRecord,
};
use std::sync::{Arc, Mutex};

#[derive(Clone)]
pub(crate) enum TestLogWriter {
FileWriter,
LogFacade(LogLevel),
Custom(Arc<dyn LogWriter>),
}

impl Default for TestLogWriter {
fn default() -> Self {
TestLogWriter::FileWriter
}
}

pub(crate) struct MockLogFacadeLogger {
logs: Arc<Mutex<Vec<String>>>,
}

impl MockLogFacadeLogger {
pub fn new() -> Self {
Self { logs: Arc::new(Mutex::new(Vec::new())) }
}

pub fn retrieve_logs(&self) -> Vec<String> {
self.logs.lock().unwrap().to_vec()
}
}

impl LogFacadeLog for MockLogFacadeLogger {
fn enabled(&self, _metadata: &log::Metadata) -> bool {
true
}

fn log(&self, record: &log::Record) {
let message = format!(
"{} {:<5} [{}:{}] {}",
Utc::now().format("%Y-%m-%d %H:%M:%S"),
record.level().to_string(),
record.module_path().unwrap(),
record.line().unwrap(),
record.args()
);
println!("{message}");
self.logs.lock().unwrap().push(message);
}

fn flush(&self) {}
}

impl LogWriter for MockLogFacadeLogger {
fn log<'a>(&self, record: LogRecord) {
let record = MockLogRecord(record).into();
LogFacadeLog::log(self, &record);
}
}

struct MockLogRecord<'a>(LogRecord<'a>);
struct MockLogLevel(LogLevel);

impl From<MockLogLevel> for LogFacadeLevel {
fn from(level: MockLogLevel) -> Self {
match level.0 {
LogLevel::Gossip | LogLevel::Trace => LogFacadeLevel::Trace,
LogLevel::Debug => LogFacadeLevel::Debug,
LogLevel::Info => LogFacadeLevel::Info,
LogLevel::Warn => LogFacadeLevel::Warn,
LogLevel::Error => LogFacadeLevel::Error,
}
}
}

impl<'a> From<MockLogRecord<'a>> for LogFacadeRecord<'a> {
fn from(log_record: MockLogRecord<'a>) -> Self {
let log_record = log_record.0;
let level = MockLogLevel(log_record.level).into();

let mut record_builder = LogFacadeRecord::builder();
let record = record_builder
.level(level)
.module_path(Some(log_record.module_path))
.line(Some(log_record.line))
.args(log_record.args);

record.build()
}
}

pub(crate) fn init_log_logger(level: LogFacadeLevelFilter) -> Arc<MockLogFacadeLogger> {
let logger = Arc::new(MockLogFacadeLogger::new());
log::set_boxed_logger(Box::new(logger.clone())).unwrap();
log::set_max_level(level);

logger
}

pub(crate) fn init_custom_logger() -> Arc<MockLogFacadeLogger> {
let logger = Arc::new(MockLogFacadeLogger::new());

logger
}

pub(crate) fn validate_log_entry(entry: &String) {
let parts = entry.splitn(4, ' ').collect::<Vec<_>>();
assert_eq!(parts.len(), 4);
let (day, time, level, path_and_msg) = (parts[0], parts[1], parts[2], parts[3]);

let day_parts = day.split('-').collect::<Vec<_>>();
assert_eq!(day_parts.len(), 3);
let (year, month, day) = (day_parts[0], day_parts[1], day_parts[2]);
assert!(year.len() == 4 && month.len() == 2 && day.len() == 2);
assert!(
year.chars().all(|c| c.is_digit(10))
&& month.chars().all(|c| c.is_digit(10))
&& day.chars().all(|c| c.is_digit(10))
);

let time_parts = time.split(':').collect::<Vec<_>>();
assert_eq!(time_parts.len(), 3);
let (hour, minute, second) = (time_parts[0], time_parts[1], time_parts[2]);
assert!(hour.len() == 2 && minute.len() == 2 && second.len() == 2);
assert!(
hour.chars().all(|c| c.is_digit(10))
&& minute.chars().all(|c| c.is_digit(10))
&& second.chars().all(|c| c.is_digit(10))
);

assert!(["GOSSIP", "TRACE", "DEBUG", "INFO", "WARN", "ERROR"].contains(&level),);

let path = path_and_msg.split_whitespace().next().unwrap();
assert!(path.contains('[') && path.contains(']'));
let module_path = &path[1..path.len() - 1];
let path_parts = module_path.rsplitn(2, ':').collect::<Vec<_>>();
assert_eq!(path_parts.len(), 2);
let (line_number, module_name) = (path_parts[0], path_parts[1]);
assert!(module_name.chars().all(|c| c.is_alphanumeric() || c == '_' || c == ':'));
assert!(line_number.chars().all(|c| c.is_digit(10)));

let msg_start_index = path_and_msg.find(']').unwrap() + 1;
let msg = &path_and_msg[msg_start_index..];
assert!(!msg.is_empty());
}
143 changes: 18 additions & 125 deletions tests/common/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -7,13 +7,14 @@

#![cfg(any(test, cln_test, vss_test))]
#![allow(dead_code)]
pub(crate) mod logging;

use logging::TestLogWriter;

use chrono::Utc;
use ldk_node::config::{
Config, EsploraSyncConfig, DEFAULT_LOG_FILENAME, DEFAULT_LOG_LEVEL, DEFAULT_STORAGE_DIR_PATH,
};
use ldk_node::io::sqlite_store::SqliteStore;
use ldk_node::logger::{LogLevel, LogRecord, LogWriter};
use ldk_node::payment::{PaymentDirection, PaymentKind, PaymentStatus};
use ldk_node::{
Builder, CustomTlvRecord, Event, LightningBalance, Node, NodeError, PendingSweepBalance,
Expand All @@ -40,13 +41,12 @@ use bitcoincore_rpc::RpcApi;
use electrsd::{bitcoind, bitcoind::BitcoinD, ElectrsD};
use electrum_client::ElectrumApi;

use log::{Level, LevelFilter, Log, Record};
use rand::distributions::Alphanumeric;
use rand::{thread_rng, Rng};

use std::env;
use std::path::PathBuf;
use std::sync::{Arc, Mutex, RwLock};
use std::sync::{Arc, RwLock};
use std::time::Duration;

macro_rules! expect_event {
Expand Down Expand Up @@ -220,28 +220,28 @@ pub(crate) fn random_node_alias() -> Option<NodeAlias> {
}

pub(crate) fn random_config(anchor_channels: bool) -> TestConfig {
let mut config = Config::default();
let mut node_config = Config::default();

if !anchor_channels {
config.anchor_channels_config = None;
node_config.anchor_channels_config = None;
}

config.network = Network::Regtest;
println!("Setting network: {}", config.network);
node_config.network = Network::Regtest;
println!("Setting network: {}", node_config.network);

let rand_dir = random_storage_path();
println!("Setting random LDK storage dir: {}", rand_dir.display());
config.storage_dir_path = rand_dir.to_str().unwrap().to_owned();
node_config.storage_dir_path = rand_dir.to_str().unwrap().to_owned();

let rand_listening_addresses = random_listening_addresses();
println!("Setting random LDK listening addresses: {:?}", rand_listening_addresses);
config.listening_addresses = Some(rand_listening_addresses);
node_config.listening_addresses = Some(rand_listening_addresses);

let alias = random_node_alias();
println!("Setting random LDK node alias: {:?}", alias);
config.node_alias = alias;
node_config.node_alias = alias;

TestConfig { node_config: config, log_writer: TestLogWriter::default() }
TestConfig { node_config, ..Default::default() }
}

#[cfg(feature = "uniffi")]
Expand All @@ -255,34 +255,12 @@ pub(crate) enum TestChainSource<'a> {
BitcoindRpc(&'a BitcoinD),
}

#[derive(Clone)]
pub(crate) enum TestLogWriter {
FileWriter { file_path: String, max_log_level: LogLevel },
LogFacade { max_log_level: LogLevel },
Custom(Arc<dyn LogWriter>),
}

impl Default for TestLogWriter {
fn default() -> Self {
TestLogWriter::FileWriter {
file_path: format!("{}/{}", DEFAULT_STORAGE_DIR_PATH, DEFAULT_LOG_FILENAME),
max_log_level: DEFAULT_LOG_LEVEL,
}
}
}

#[derive(Clone)]
#[derive(Clone, Default)]
pub(crate) struct TestConfig {
pub node_config: Config,
pub log_writer: TestLogWriter,
}

impl Default for TestConfig {
fn default() -> Self {
Self { node_config: Config::default(), log_writer: TestLogWriter::default() }
}
}

macro_rules! setup_builder {
($builder: ident, $config: expr) => {
#[cfg(feature = "uniffi")]
Expand Down Expand Up @@ -343,10 +321,12 @@ pub(crate) fn setup_node(
}

match &config.log_writer {
TestLogWriter::FileWriter { file_path, max_log_level } => {
builder.set_filesystem_logger(Some(file_path.clone()), Some(*max_log_level));
TestLogWriter::FileWriter => {
let file_path = format!("{}/{}", DEFAULT_STORAGE_DIR_PATH, DEFAULT_LOG_FILENAME);
let max_log_level = DEFAULT_LOG_LEVEL;
builder.set_filesystem_logger(Some(file_path), Some(max_log_level));
},
TestLogWriter::LogFacade { max_log_level } => {
TestLogWriter::LogFacade(max_log_level) => {
builder.set_log_facade_logger(Some(*max_log_level));
},
TestLogWriter::Custom(custom_log_writer) => {
Expand Down Expand Up @@ -1209,90 +1189,3 @@ impl KVStore for TestSyncStore {
self.do_list(primary_namespace, secondary_namespace)
}
}

pub(crate) struct MockLogger {
logs: Arc<Mutex<Vec<String>>>,
}

impl MockLogger {
pub fn new() -> Self {
Self { logs: Arc::new(Mutex::new(Vec::new())) }
}

pub fn retrieve_logs(&self) -> Vec<String> {
self.logs.lock().unwrap().to_vec()
}
}

impl Log for MockLogger {
fn enabled(&self, _metadata: &log::Metadata) -> bool {
true
}

fn log(&self, record: &log::Record) {
let message = format!(
"{} {:<5} [{}:{}] {}",
Utc::now().format("%Y-%m-%d %H:%M:%S"),
record.level().to_string(),
record.module_path().unwrap(),
record.line().unwrap(),
record.args()
);
println!("{message}");
self.logs.lock().unwrap().push(message);
}

fn flush(&self) {}
}

impl LogWriter for MockLogger {
fn log<'a>(&self, record: LogRecord) {
let record = MockLogRecord(record).into();
Log::log(self, &record);
}
}

struct MockLogRecord<'a>(LogRecord<'a>);
struct MockLogLevel(LogLevel);

impl From<MockLogLevel> for Level {
fn from(level: MockLogLevel) -> Self {
match level.0 {
LogLevel::Gossip | LogLevel::Trace => Level::Trace,
LogLevel::Debug => Level::Debug,
LogLevel::Info => Level::Info,
LogLevel::Warn => Level::Warn,
LogLevel::Error => Level::Error,
}
}
}

impl<'a> From<MockLogRecord<'a>> for Record<'a> {
fn from(log_record: MockLogRecord<'a>) -> Self {
let log_record = log_record.0;
let level = MockLogLevel(log_record.level).into();

let mut record_builder = Record::builder();
let record = record_builder
.level(level)
.module_path(Some(log_record.module_path))
.line(Some(log_record.line))
.args(log_record.args);

record.build()
}
}

pub(crate) fn init_log_logger(level: LevelFilter) -> Arc<MockLogger> {
let logger = Arc::new(MockLogger::new());
log::set_boxed_logger(Box::new(logger.clone())).unwrap();
log::set_max_level(level);

logger
}

pub(crate) fn init_custom_logger() -> Arc<MockLogger> {
let logger = Arc::new(MockLogger::new());

logger
}
Loading

0 comments on commit 30bee82

Please sign in to comment.