Skip to content

Commit d1bbf97

Browse files
authored
Merge pull request #751 from joostjager/structured-logging
Add structured logging context fields to LogRecord
2 parents ee617ef + 4f86a64 commit d1bbf97

File tree

3 files changed

+219
-8
lines changed

3 files changed

+219
-8
lines changed

bindings/ldk_node.udl

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -83,6 +83,9 @@ dictionary LogRecord {
8383
string args;
8484
string module_path;
8585
u32 line;
86+
PublicKey? peer_id;
87+
ChannelId? channel_id;
88+
PaymentHash? payment_hash;
8689
};
8790

8891
[Trait, WithForeign]

src/logger.rs

Lines changed: 208 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -7,14 +7,16 @@
77

88
//! Logging-related objects.
99
10-
#[cfg(not(feature = "uniffi"))]
1110
use core::fmt;
1211
use std::fs;
1312
use std::io::Write;
1413
use std::path::Path;
1514
use std::sync::Arc;
1615

16+
use bitcoin::secp256k1::PublicKey;
1717
use chrono::Utc;
18+
use lightning::ln::types::ChannelId;
19+
use lightning::types::payment::PaymentHash;
1820
pub use lightning::util::logger::Level as LogLevel;
1921
pub(crate) use lightning::util::logger::{Logger as LdkLogger, Record as LdkRecord};
2022
pub(crate) use lightning::{log_bytes, log_debug, log_error, log_info, log_trace};
@@ -32,6 +34,64 @@ pub struct LogRecord<'a> {
3234
pub module_path: &'a str,
3335
/// The line containing the message.
3436
pub line: u32,
37+
/// The node id of the peer pertaining to the logged record.
38+
pub peer_id: Option<PublicKey>,
39+
/// The channel id of the channel pertaining to the logged record.
40+
pub channel_id: Option<ChannelId>,
41+
/// The payment hash pertaining to the logged record.
42+
pub payment_hash: Option<PaymentHash>,
43+
}
44+
45+
/// Structured context fields for log messages.
46+
///
47+
/// Implements `Display` to format context fields (channel_id, peer_id, payment_hash) directly
48+
/// into a formatter, avoiding intermediate heap allocations when used with `format_args!` or
49+
/// `write!` macros.
50+
///
51+
/// Note: LDK's `Record` Display implementation uses fixed-width padded columns and different
52+
/// formatting for test vs production builds. We intentionally use a simpler format here:
53+
/// fields are only included when present (no padding), and the format is consistent across
54+
/// all build configurations.
55+
pub struct LogContext<'a> {
56+
/// The channel id of the channel pertaining to the logged record.
57+
pub channel_id: Option<&'a ChannelId>,
58+
/// The node id of the peer pertaining to the logged record.
59+
pub peer_id: Option<&'a PublicKey>,
60+
/// The payment hash pertaining to the logged record.
61+
pub payment_hash: Option<&'a PaymentHash>,
62+
}
63+
64+
impl fmt::Display for LogContext<'_> {
65+
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
66+
fn truncate(s: &str) -> &str {
67+
&s[..s.len().min(6)]
68+
}
69+
70+
if self.channel_id.is_none() && self.peer_id.is_none() && self.payment_hash.is_none() {
71+
return Ok(());
72+
}
73+
74+
write!(f, " (")?;
75+
let mut need_space = false;
76+
if let Some(c) = self.channel_id {
77+
write!(f, "ch:{}", truncate(&c.to_string()))?;
78+
need_space = true;
79+
}
80+
if let Some(p) = self.peer_id {
81+
if need_space {
82+
write!(f, " ")?;
83+
}
84+
write!(f, "p:{}", truncate(&p.to_string()))?;
85+
need_space = true;
86+
}
87+
if let Some(h) = self.payment_hash {
88+
if need_space {
89+
write!(f, " ")?;
90+
}
91+
write!(f, "h:{}", truncate(&format!("{:?}", h)))?;
92+
}
93+
write!(f, ")")
94+
}
3595
}
3696

3797
/// A unit of logging output with metadata to enable filtering `module_path`,
@@ -50,6 +110,12 @@ pub struct LogRecord {
50110
pub module_path: String,
51111
/// The line containing the message.
52112
pub line: u32,
113+
/// The node id of the peer pertaining to the logged record.
114+
pub peer_id: Option<PublicKey>,
115+
/// The channel id of the channel pertaining to the logged record.
116+
pub channel_id: Option<ChannelId>,
117+
/// The payment hash pertaining to the logged record.
118+
pub payment_hash: Option<PaymentHash>,
53119
}
54120

55121
#[cfg(feature = "uniffi")]
@@ -60,6 +126,9 @@ impl<'a> From<LdkRecord<'a>> for LogRecord {
60126
args: record.args.to_string(),
61127
module_path: record.module_path.to_string(),
62128
line: record.line,
129+
peer_id: record.peer_id,
130+
channel_id: record.channel_id,
131+
payment_hash: record.payment_hash,
63132
}
64133
}
65134
}
@@ -72,6 +141,9 @@ impl<'a> From<LdkRecord<'a>> for LogRecord<'a> {
72141
args: record.args,
73142
module_path: record.module_path,
74143
line: record.line,
144+
peer_id: record.peer_id,
145+
channel_id: record.channel_id,
146+
payment_hash: record.payment_hash,
75147
}
76148
}
77149
}
@@ -113,19 +185,26 @@ pub(crate) enum Writer {
113185

114186
impl LogWriter for Writer {
115187
fn log(&self, record: LogRecord) {
188+
let context = LogContext {
189+
channel_id: record.channel_id.as_ref(),
190+
peer_id: record.peer_id.as_ref(),
191+
payment_hash: record.payment_hash.as_ref(),
192+
};
193+
116194
match self {
117195
Writer::FileWriter { file_path, max_log_level } => {
118196
if record.level < *max_log_level {
119197
return;
120198
}
121199

122200
let log = format!(
123-
"{} {:<5} [{}:{}] {}\n",
201+
"{} {:<5} [{}:{}] {}{}\n",
124202
Utc::now().format("%Y-%m-%d %H:%M:%S%.3f"),
125203
record.level.to_string(),
126204
record.module_path,
127205
record.line,
128-
record.args
206+
record.args,
207+
context,
129208
);
130209

131210
fs::OpenOptions::new()
@@ -153,7 +232,7 @@ impl LogWriter for Writer {
153232
.target(record.module_path)
154233
.module_path(Some(record.module_path))
155234
.line(Some(record.line))
156-
.args(format_args!("{}", record.args))
235+
.args(format_args!("{}{}", record.args, context))
157236
.build(),
158237
);
159238
#[cfg(feature = "uniffi")]
@@ -162,7 +241,7 @@ impl LogWriter for Writer {
162241
.target(&record.module_path)
163242
.module_path(Some(&record.module_path))
164243
.line(Some(record.line))
165-
.args(format_args!("{}", record.args))
244+
.args(format_args!("{}{}", record.args, context))
166245
.build(),
167246
);
168247
},
@@ -222,3 +301,127 @@ impl LdkLogger for Logger {
222301
}
223302
}
224303
}
304+
305+
#[cfg(test)]
306+
mod tests {
307+
use super::*;
308+
use std::sync::Mutex;
309+
310+
/// A minimal log facade logger that captures log output for testing.
311+
struct TestLogger {
312+
log: Arc<Mutex<String>>,
313+
}
314+
315+
impl log::Log for TestLogger {
316+
fn enabled(&self, _metadata: &log::Metadata) -> bool {
317+
true
318+
}
319+
320+
fn log(&self, record: &log::Record) {
321+
*self.log.lock().unwrap() = record.args().to_string();
322+
}
323+
324+
fn flush(&self) {}
325+
}
326+
327+
/// Tests that LogContext correctly formats all three structured fields
328+
/// (channel_id, peer_id, payment_hash) with space prefixes and 6-char truncation.
329+
#[test]
330+
fn test_log_context_all_fields() {
331+
let channel_id = ChannelId::from_bytes([
332+
0xab, 0xcd, 0xef, 0x12, 0x34, 0x56, 0x78, 0x90, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
333+
0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
334+
0x00, 0x00, 0x00, 0x00,
335+
]);
336+
let peer_id = PublicKey::from_slice(&[
337+
0x02, 0xab, 0xcd, 0xef, 0x12, 0x34, 0x56, 0x78, 0x9a, 0xbc, 0xde, 0xf1, 0x23, 0x45,
338+
0x67, 0x89, 0xab, 0xcd, 0xef, 0x12, 0x34, 0x56, 0x78, 0x9a, 0xbc, 0xde, 0xf1, 0x23,
339+
0x45, 0x67, 0x89, 0xab, 0xcd,
340+
])
341+
.unwrap();
342+
let payment_hash = PaymentHash([
343+
0xfe, 0xdc, 0xba, 0x98, 0x76, 0x54, 0x32, 0x10, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
344+
0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
345+
0x00, 0x00, 0x00, 0x00,
346+
]);
347+
348+
let context = LogContext {
349+
channel_id: Some(&channel_id),
350+
peer_id: Some(&peer_id),
351+
payment_hash: Some(&payment_hash),
352+
};
353+
354+
assert_eq!(context.to_string(), " (ch:abcdef p:02abcd h:fedcba)");
355+
}
356+
357+
/// Tests that LogContext returns an empty string when no fields are provided.
358+
#[test]
359+
fn test_log_context_no_fields() {
360+
let context = LogContext { channel_id: None, peer_id: None, payment_hash: None };
361+
assert_eq!(context.to_string(), "");
362+
}
363+
364+
/// Tests that LogContext only includes present fields.
365+
#[test]
366+
fn test_log_context_partial_fields() {
367+
let channel_id = ChannelId::from_bytes([
368+
0x12, 0x34, 0x56, 0x78, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
369+
0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
370+
0x00, 0x00, 0x00, 0x00,
371+
]);
372+
373+
let context =
374+
LogContext { channel_id: Some(&channel_id), peer_id: None, payment_hash: None };
375+
assert_eq!(context.to_string(), " (ch:123456)");
376+
}
377+
378+
/// Tests that LogFacadeWriter appends structured context fields to the log message.
379+
#[test]
380+
fn test_log_facade_writer_includes_structured_context() {
381+
let log = Arc::new(Mutex::new(String::new()));
382+
let test_logger = TestLogger { log: log.clone() };
383+
384+
let _ = log::set_boxed_logger(Box::new(test_logger));
385+
log::set_max_level(log::LevelFilter::Trace);
386+
387+
let writer = Writer::LogFacadeWriter;
388+
389+
let channel_id = ChannelId::from_bytes([
390+
0xab, 0xcd, 0xef, 0x12, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
391+
0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
392+
0x00, 0x00, 0x00, 0x00,
393+
]);
394+
let peer_id = PublicKey::from_slice(&[
395+
0x02, 0xab, 0xcd, 0xef, 0x12, 0x34, 0x56, 0x78, 0x9a, 0xbc, 0xde, 0xf1, 0x23, 0x45,
396+
0x67, 0x89, 0xab, 0xcd, 0xef, 0x12, 0x34, 0x56, 0x78, 0x9a, 0xbc, 0xde, 0xf1, 0x23,
397+
0x45, 0x67, 0x89, 0xab, 0xcd,
398+
])
399+
.unwrap();
400+
401+
#[cfg(not(feature = "uniffi"))]
402+
let record = LogRecord {
403+
level: LogLevel::Info,
404+
args: format_args!("Test message"),
405+
module_path: "test_module",
406+
line: 42,
407+
peer_id: Some(peer_id),
408+
channel_id: Some(channel_id),
409+
payment_hash: None,
410+
};
411+
412+
#[cfg(feature = "uniffi")]
413+
let record = LogRecord {
414+
level: LogLevel::Info,
415+
args: "Test message".to_string(),
416+
module_path: "test_module".to_string(),
417+
line: 42,
418+
peer_id: Some(peer_id),
419+
channel_id: Some(channel_id),
420+
payment_hash: None,
421+
};
422+
423+
writer.log(record);
424+
425+
assert_eq!(*log.lock().unwrap(), "Test message (ch:abcdef p:02abcd)");
426+
}
427+
}

tests/common/logging.rs

Lines changed: 8 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11
use std::sync::{Arc, Mutex};
22

33
use chrono::Utc;
4-
use ldk_node::logger::{LogLevel, LogRecord, LogWriter};
4+
use ldk_node::logger::{LogContext, LogLevel, LogRecord, LogWriter};
55
#[cfg(not(feature = "uniffi"))]
66
use log::Record as LogFacadeRecord;
77
use log::{Level as LogFacadeLevel, LevelFilter as LogFacadeLevelFilter, Log as LogFacadeLog};
@@ -156,13 +156,18 @@ impl MultiNodeLogger {
156156
impl LogWriter for MultiNodeLogger {
157157
fn log(&self, record: LogRecord) {
158158
let log = format!(
159-
"[{}] {} {:<5} [{}:{}] {}\n",
159+
"[{}] {} {:<5} [{}:{}] {}{}\n",
160160
self.node_id,
161161
Utc::now().format("%Y-%m-%d %H:%M:%S%.3f"),
162162
record.level.to_string(),
163163
record.module_path,
164164
record.line,
165-
record.args
165+
record.args,
166+
LogContext {
167+
channel_id: record.channel_id.as_ref(),
168+
peer_id: record.peer_id.as_ref(),
169+
payment_hash: record.payment_hash.as_ref(),
170+
},
166171
);
167172

168173
print!("{}", log);

0 commit comments

Comments
 (0)