Skip to content

Commit bff5778

Browse files
enigbeenigbe
committed
fix: add logging module and validate log entries
Additionally addresses minor issues related to: - Default impl - Verbose TestLogWriter enum - MockLogFacadeLogger and node_config rename
1 parent 33a425b commit bff5778

File tree

3 files changed

+179
-134
lines changed

3 files changed

+179
-134
lines changed

‎tests/common/logging.rs

Lines changed: 148 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,148 @@
1+
use chrono::Utc;
2+
use ldk_node::logger::{LogLevel, LogRecord, LogWriter};
3+
use log::{
4+
Level as LogFacadeLevel, LevelFilter as LogFacadeLevelFilter, Log as LogFacadeLog,
5+
Record as LogFacadeRecord,
6+
};
7+
use std::sync::{Arc, Mutex};
8+
9+
#[derive(Clone)]
10+
pub(crate) enum TestLogWriter {
11+
FileWriter,
12+
LogFacade(LogLevel),
13+
Custom(Arc<dyn LogWriter>),
14+
}
15+
16+
impl Default for TestLogWriter {
17+
fn default() -> Self {
18+
TestLogWriter::FileWriter
19+
}
20+
}
21+
22+
pub(crate) struct MockLogFacadeLogger {
23+
logs: Arc<Mutex<Vec<String>>>,
24+
}
25+
26+
impl MockLogFacadeLogger {
27+
pub fn new() -> Self {
28+
Self { logs: Arc::new(Mutex::new(Vec::new())) }
29+
}
30+
31+
pub fn retrieve_logs(&self) -> Vec<String> {
32+
self.logs.lock().unwrap().to_vec()
33+
}
34+
}
35+
36+
impl LogFacadeLog for MockLogFacadeLogger {
37+
fn enabled(&self, _metadata: &log::Metadata) -> bool {
38+
true
39+
}
40+
41+
fn log(&self, record: &log::Record) {
42+
let message = format!(
43+
"{} {:<5} [{}:{}] {}",
44+
Utc::now().format("%Y-%m-%d %H:%M:%S"),
45+
record.level().to_string(),
46+
record.module_path().unwrap(),
47+
record.line().unwrap(),
48+
record.args()
49+
);
50+
println!("{message}");
51+
self.logs.lock().unwrap().push(message);
52+
}
53+
54+
fn flush(&self) {}
55+
}
56+
57+
impl LogWriter for MockLogFacadeLogger {
58+
fn log<'a>(&self, record: LogRecord) {
59+
let record = MockLogRecord(record).into();
60+
LogFacadeLog::log(self, &record);
61+
}
62+
}
63+
64+
struct MockLogRecord<'a>(LogRecord<'a>);
65+
struct MockLogLevel(LogLevel);
66+
67+
impl From<MockLogLevel> for LogFacadeLevel {
68+
fn from(level: MockLogLevel) -> Self {
69+
match level.0 {
70+
LogLevel::Gossip | LogLevel::Trace => LogFacadeLevel::Trace,
71+
LogLevel::Debug => LogFacadeLevel::Debug,
72+
LogLevel::Info => LogFacadeLevel::Info,
73+
LogLevel::Warn => LogFacadeLevel::Warn,
74+
LogLevel::Error => LogFacadeLevel::Error,
75+
}
76+
}
77+
}
78+
79+
impl<'a> From<MockLogRecord<'a>> for LogFacadeRecord<'a> {
80+
fn from(log_record: MockLogRecord<'a>) -> Self {
81+
let log_record = log_record.0;
82+
let level = MockLogLevel(log_record.level).into();
83+
84+
let mut record_builder = LogFacadeRecord::builder();
85+
let record = record_builder
86+
.level(level)
87+
.module_path(Some(log_record.module_path))
88+
.line(Some(log_record.line))
89+
.args(log_record.args);
90+
91+
record.build()
92+
}
93+
}
94+
95+
pub(crate) fn init_log_logger(level: LogFacadeLevelFilter) -> Arc<MockLogFacadeLogger> {
96+
let logger = Arc::new(MockLogFacadeLogger::new());
97+
log::set_boxed_logger(Box::new(logger.clone())).unwrap();
98+
log::set_max_level(level);
99+
100+
logger
101+
}
102+
103+
pub(crate) fn init_custom_logger() -> Arc<MockLogFacadeLogger> {
104+
let logger = Arc::new(MockLogFacadeLogger::new());
105+
106+
logger
107+
}
108+
109+
pub(crate) fn validate_log_entry(entry: &String) {
110+
let parts = entry.splitn(4, ' ').collect::<Vec<_>>();
111+
assert_eq!(parts.len(), 4);
112+
let (day, time, level, path_and_msg) = (parts[0], parts[1], parts[2], parts[3]);
113+
114+
let day_parts = day.split('-').collect::<Vec<_>>();
115+
assert_eq!(day_parts.len(), 3);
116+
let (year, month, day) = (day_parts[0], day_parts[1], day_parts[2]);
117+
assert!(year.len() == 4 && month.len() == 2 && day.len() == 2);
118+
assert!(
119+
year.chars().all(|c| c.is_digit(10))
120+
&& month.chars().all(|c| c.is_digit(10))
121+
&& day.chars().all(|c| c.is_digit(10))
122+
);
123+
124+
let time_parts = time.split(':').collect::<Vec<_>>();
125+
assert_eq!(time_parts.len(), 3);
126+
let (hour, minute, second) = (time_parts[0], time_parts[1], time_parts[2]);
127+
assert!(hour.len() == 2 && minute.len() == 2 && second.len() == 2);
128+
assert!(
129+
hour.chars().all(|c| c.is_digit(10))
130+
&& minute.chars().all(|c| c.is_digit(10))
131+
&& second.chars().all(|c| c.is_digit(10))
132+
);
133+
134+
assert!(["GOSSIP", "TRACE", "DEBUG", "INFO", "WARN", "ERROR"].contains(&level),);
135+
136+
let path = path_and_msg.split_whitespace().next().unwrap();
137+
assert!(path.contains('[') && path.contains(']'));
138+
let module_path = &path[1..path.len() - 1];
139+
let path_parts = module_path.rsplitn(2, ':').collect::<Vec<_>>();
140+
assert_eq!(path_parts.len(), 2);
141+
let (line_number, module_name) = (path_parts[0], path_parts[1]);
142+
assert!(module_name.chars().all(|c| c.is_alphanumeric() || c == '_' || c == ':'));
143+
assert!(line_number.chars().all(|c| c.is_digit(10)));
144+
145+
let msg_start_index = path_and_msg.find(']').unwrap() + 1;
146+
let msg = &path_and_msg[msg_start_index..];
147+
assert!(!msg.is_empty());
148+
}

‎tests/common/mod.rs

Lines changed: 18 additions & 125 deletions
Original file line numberDiff line numberDiff line change
@@ -7,13 +7,14 @@
77

88
#![cfg(any(test, cln_test, vss_test))]
99
#![allow(dead_code)]
10+
pub(crate) mod logging;
11+
12+
use logging::TestLogWriter;
1013

11-
use chrono::Utc;
1214
use ldk_node::config::{
1315
Config, EsploraSyncConfig, DEFAULT_LOG_FILENAME, DEFAULT_LOG_LEVEL, DEFAULT_STORAGE_DIR_PATH,
1416
};
1517
use ldk_node::io::sqlite_store::SqliteStore;
16-
use ldk_node::logger::{LogLevel, LogRecord, LogWriter};
1718
use ldk_node::payment::{PaymentDirection, PaymentKind, PaymentStatus};
1819
use ldk_node::{
1920
Builder, CustomTlvRecord, Event, LightningBalance, Node, NodeError, PendingSweepBalance,
@@ -40,13 +41,12 @@ use bitcoincore_rpc::RpcApi;
4041
use electrsd::{bitcoind, bitcoind::BitcoinD, ElectrsD};
4142
use electrum_client::ElectrumApi;
4243

43-
use log::{Level, LevelFilter, Log, Record};
4444
use rand::distributions::Alphanumeric;
4545
use rand::{thread_rng, Rng};
4646

4747
use std::env;
4848
use std::path::PathBuf;
49-
use std::sync::{Arc, Mutex, RwLock};
49+
use std::sync::{Arc, RwLock};
5050
use std::time::Duration;
5151

5252
macro_rules! expect_event {
@@ -220,28 +220,28 @@ pub(crate) fn random_node_alias() -> Option<NodeAlias> {
220220
}
221221

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

225225
if !anchor_channels {
226-
config.anchor_channels_config = None;
226+
node_config.anchor_channels_config = None;
227227
}
228228

229-
config.network = Network::Regtest;
230-
println!("Setting network: {}", config.network);
229+
node_config.network = Network::Regtest;
230+
println!("Setting network: {}", node_config.network);
231231

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

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

240240
let alias = random_node_alias();
241241
println!("Setting random LDK node alias: {:?}", alias);
242-
config.node_alias = alias;
242+
node_config.node_alias = alias;
243243

244-
TestConfig { node_config: config, log_writer: TestLogWriter::default() }
244+
TestConfig { node_config, ..Default::default() }
245245
}
246246

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

258-
#[derive(Clone)]
259-
pub(crate) enum TestLogWriter {
260-
FileWriter { file_path: String, max_log_level: LogLevel },
261-
LogFacade { max_log_level: LogLevel },
262-
Custom(Arc<dyn LogWriter>),
263-
}
264-
265-
impl Default for TestLogWriter {
266-
fn default() -> Self {
267-
TestLogWriter::FileWriter {
268-
file_path: format!("{}/{}", DEFAULT_STORAGE_DIR_PATH, DEFAULT_LOG_FILENAME),
269-
max_log_level: DEFAULT_LOG_LEVEL,
270-
}
271-
}
272-
}
273-
274-
#[derive(Clone)]
258+
#[derive(Clone, Default)]
275259
pub(crate) struct TestConfig {
276260
pub node_config: Config,
277261
pub log_writer: TestLogWriter,
278262
}
279263

280-
impl Default for TestConfig {
281-
fn default() -> Self {
282-
Self { node_config: Config::default(), log_writer: TestLogWriter::default() }
283-
}
284-
}
285-
286264
macro_rules! setup_builder {
287265
($builder: ident, $config: expr) => {
288266
#[cfg(feature = "uniffi")]
@@ -343,10 +321,12 @@ pub(crate) fn setup_node(
343321
}
344322

345323
match &config.log_writer {
346-
TestLogWriter::FileWriter { file_path, max_log_level } => {
347-
builder.set_filesystem_logger(Some(file_path.clone()), Some(*max_log_level));
324+
TestLogWriter::FileWriter => {
325+
let file_path = format!("{}/{}", DEFAULT_STORAGE_DIR_PATH, DEFAULT_LOG_FILENAME);
326+
let max_log_level = DEFAULT_LOG_LEVEL;
327+
builder.set_filesystem_logger(Some(file_path), Some(max_log_level));
348328
},
349-
TestLogWriter::LogFacade { max_log_level } => {
329+
TestLogWriter::LogFacade(max_log_level) => {
350330
builder.set_log_facade_logger(Some(*max_log_level));
351331
},
352332
TestLogWriter::Custom(custom_log_writer) => {
@@ -1209,90 +1189,3 @@ impl KVStore for TestSyncStore {
12091189
self.do_list(primary_namespace, secondary_namespace)
12101190
}
12111191
}
1212-
1213-
pub(crate) struct MockLogger {
1214-
logs: Arc<Mutex<Vec<String>>>,
1215-
}
1216-
1217-
impl MockLogger {
1218-
pub fn new() -> Self {
1219-
Self { logs: Arc::new(Mutex::new(Vec::new())) }
1220-
}
1221-
1222-
pub fn retrieve_logs(&self) -> Vec<String> {
1223-
self.logs.lock().unwrap().to_vec()
1224-
}
1225-
}
1226-
1227-
impl Log for MockLogger {
1228-
fn enabled(&self, _metadata: &log::Metadata) -> bool {
1229-
true
1230-
}
1231-
1232-
fn log(&self, record: &log::Record) {
1233-
let message = format!(
1234-
"{} {:<5} [{}:{}] {}",
1235-
Utc::now().format("%Y-%m-%d %H:%M:%S"),
1236-
record.level().to_string(),
1237-
record.module_path().unwrap(),
1238-
record.line().unwrap(),
1239-
record.args()
1240-
);
1241-
println!("{message}");
1242-
self.logs.lock().unwrap().push(message);
1243-
}
1244-
1245-
fn flush(&self) {}
1246-
}
1247-
1248-
impl LogWriter for MockLogger {
1249-
fn log<'a>(&self, record: LogRecord) {
1250-
let record = MockLogRecord(record).into();
1251-
Log::log(self, &record);
1252-
}
1253-
}
1254-
1255-
struct MockLogRecord<'a>(LogRecord<'a>);
1256-
struct MockLogLevel(LogLevel);
1257-
1258-
impl From<MockLogLevel> for Level {
1259-
fn from(level: MockLogLevel) -> Self {
1260-
match level.0 {
1261-
LogLevel::Gossip | LogLevel::Trace => Level::Trace,
1262-
LogLevel::Debug => Level::Debug,
1263-
LogLevel::Info => Level::Info,
1264-
LogLevel::Warn => Level::Warn,
1265-
LogLevel::Error => Level::Error,
1266-
}
1267-
}
1268-
}
1269-
1270-
impl<'a> From<MockLogRecord<'a>> for Record<'a> {
1271-
fn from(log_record: MockLogRecord<'a>) -> Self {
1272-
let log_record = log_record.0;
1273-
let level = MockLogLevel(log_record.level).into();
1274-
1275-
let mut record_builder = Record::builder();
1276-
let record = record_builder
1277-
.level(level)
1278-
.module_path(Some(log_record.module_path))
1279-
.line(Some(log_record.line))
1280-
.args(log_record.args);
1281-
1282-
record.build()
1283-
}
1284-
}
1285-
1286-
pub(crate) fn init_log_logger(level: LevelFilter) -> Arc<MockLogger> {
1287-
let logger = Arc::new(MockLogger::new());
1288-
log::set_boxed_logger(Box::new(logger.clone())).unwrap();
1289-
log::set_max_level(level);
1290-
1291-
logger
1292-
}
1293-
1294-
pub(crate) fn init_custom_logger() -> Arc<MockLogger> {
1295-
let logger = Arc::new(MockLogger::new());
1296-
1297-
logger
1298-
}

0 commit comments

Comments
 (0)