_ Git - rust-lightning/blob - lightning/src/util/logger.rs

   1 // Pruned copy of crate rust log, without global logger
   2 // https://github.com/rust-lang-nursery/log #7a60286
   3 //
   4 // This file is licensed under the Apache License, Version 2.0 <LICENSE-APACHE
   5 // or http://www.apache.org/licenses/LICENSE-2.0> or the MIT license
   6 // <LICENSE-MIT or http://opensource.org/licenses/MIT>, at your option.
   7 // You may not use this file except in accordance with one or both of these
   8 // licenses.
   9
  10 //! Log traits live here, which are called throughout the library to provide useful information for
  11 //! debugging purposes.
  12 //!
  13 //! There is currently 2 ways to filter log messages. First one, by using compilation features, e.g "max_level_off".
  14 //! The second one, client-side by implementing check against Record Level field.
  15 //! Each module may have its own Logger or share one.
  16
  17 use bitcoin::secp256k1::PublicKey;
  18
  19 use core::cmp;
  20 use core::fmt;
  21 use core::ops::Deref;
  22
  23 use crate::ln::types::ChannelId;
  24 use crate::ln::PaymentHash;
  25 #[cfg(c_bindings)]
  26 use crate::prelude::*; // Needed for String
  27
  28 static LOG_LEVEL_NAMES: [&'static str; 6] = ["GOSSIP", "TRACE", "DEBUG", "INFO", "WARN", "ERROR"];
  29
  30 /// An enum representing the available verbosity levels of the logger.
  31 #[derive(Copy, Clone, PartialEq, Eq, Debug, Hash)]
  32 pub enum Level {
  33         /// Designates extremely verbose information, including gossip-induced messages
  34         Gossip,
  35         /// Designates very low priority, often extremely verbose, information
  36         Trace,
  37         /// Designates lower priority information
  38         Debug,
  39         /// Designates useful information
  40         Info,
  41         /// Designates hazardous situations
  42         Warn,
  43         /// Designates very serious errors
  44         Error,
  45 }
  46
  47 impl PartialOrd for Level {
  48         #[inline]
  49         fn partial_cmp(&self, other: &Level) -> Option<cmp::Ordering> {
  50                 Some(self.cmp(other))
  51         }
  52
  53         #[inline]
  54         fn lt(&self, other: &Level) -> bool {
  55                 (*self as usize) < *other as usize
  56         }
  57
  58         #[inline]
  59         fn le(&self, other: &Level) -> bool {
  60                 *self as usize <= *other as usize
  61         }
  62
  63         #[inline]
  64         fn gt(&self, other: &Level) -> bool {
  65                 *self as usize > *other as usize
  66         }
  67
  68         #[inline]
  69         fn ge(&self, other: &Level) -> bool {
  70                 *self as usize >= *other as usize
  71         }
  72 }
  73
  74 impl Ord for Level {
  75         #[inline]
  76         fn cmp(&self, other: &Level) -> cmp::Ordering {
  77                 (*self as usize).cmp(&(*other as usize))
  78         }
  79 }
  80
  81 impl fmt::Display for Level {
  82         fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result {
  83                 fmt.pad(LOG_LEVEL_NAMES[*self as usize])
  84         }
  85 }
  86
  87 impl Level {
  88         /// Returns the most verbose logging level.
  89         #[inline]
  90         pub fn max() -> Level {
  91                 Level::Gossip
  92         }
  93 }
  94
  95 macro_rules! impl_record {
  96         ($($args: lifetime)?, $($nonstruct_args: lifetime)?) => {
  97 /// A Record, unit of logging output with Metadata to enable filtering
  98 /// Module_path, file, line to inform on log's source
  99 #[derive(Clone, Debug)]
 100 pub struct Record<$($args)?> {
 101         /// The verbosity level of the message.
 102         pub level: Level,
 103         /// The node id of the peer pertaining to the logged record.
 104         ///
 105         /// Note that in some cases a [`Self::channel_id`] may be filled in but this may still be
 106         /// `None`, depending on if the peer information is readily available in LDK when the log is
 107         /// generated.
 108         pub peer_id: Option<PublicKey>,
 109         /// The channel id of the channel pertaining to the logged record. May be a temporary id before
 110         /// the channel has been funded.
 111         pub channel_id: Option<ChannelId>,
 112         #[cfg(not(c_bindings))]
 113         /// The message body.
 114         pub args: fmt::Arguments<'a>,
 115         #[cfg(c_bindings)]
 116         /// The message body.
 117         pub args: String,
 118         /// The module path of the message.
 119         pub module_path: &'static str,
 120         /// The source file containing the message.
 121         pub file: &'static str,
 122         /// The line containing the message.
 123         pub line: u32,
 124         /// The payment hash.
 125         ///
 126         /// Note that this is only filled in for logs pertaining to a specific payment, and will be
 127         /// `None` for logs which are not directly related to a payment.
 128         pub payment_hash: Option<PaymentHash>,
 129 }
 130
 131 impl<$($args)?> Record<$($args)?> {
 132         /// Returns a new Record.
 133         ///
 134         /// This is not exported to bindings users as fmt can't be used in C
 135         #[inline]
 136         pub fn new<$($nonstruct_args)?>(
 137                 level: Level, peer_id: Option<PublicKey>, channel_id: Option<ChannelId>,
 138                 args: fmt::Arguments<'a>, module_path: &'static str, file: &'static str, line: u32,
 139                 payment_hash: Option<PaymentHash>
 140         ) -> Record<$($args)?> {
 141                 Record {
 142                         level,
 143                         peer_id,
 144                         channel_id,
 145                         #[cfg(not(c_bindings))]
 146                         args,
 147                         #[cfg(c_bindings)]
 148                         args: format!("{}", args),
 149                         module_path,
 150                         file,
 151                         line,
 152                         payment_hash,
 153                 }
 154         }
 155 }
 156 } }
 157 #[cfg(not(c_bindings))]
 158 impl_record!('a, );
 159 #[cfg(c_bindings)]
 160 impl_record!(, 'a);
 161
 162 /// A trait encapsulating the operations required of a logger.
 163 pub trait Logger {
 164         /// Logs the [`Record`].
 165         fn log(&self, record: Record);
 166 }
 167
 168 /// Adds relevant context to a [`Record`] before passing it to the wrapped [`Logger`].
 169 ///
 170 /// This is not exported to bindings users as lifetimes are problematic and there's little reason
 171 /// for this to be used downstream anyway.
 172 pub struct WithContext<'a, L: Deref> where L::Target: Logger {
 173         /// The logger to delegate to after adding context to the record.
 174         logger: &'a L,
 175         /// The node id of the peer pertaining to the logged record.
 176         peer_id: Option<PublicKey>,
 177         /// The channel id of the channel pertaining to the logged record.
 178         channel_id: Option<ChannelId>,
 179         /// The payment hash of the payment pertaining to the logged record.
 180         payment_hash: Option<PaymentHash>
 181 }
 182
 183 impl<'a, L: Deref> Logger for WithContext<'a, L> where L::Target: Logger {
 184         fn log(&self, mut record: Record) {
 185                 if self.peer_id.is_some() {
 186                         record.peer_id = self.peer_id
 187                 };
 188                 if self.channel_id.is_some() {
 189                         record.channel_id = self.channel_id;
 190                 }
 191                 if self.payment_hash.is_some() {
 192                         record.payment_hash = self.payment_hash;
 193                 }
 194                 self.logger.log(record)
 195         }
 196 }
 197
 198 impl<'a, L: Deref> WithContext<'a, L> where L::Target: Logger {
 199         /// Wraps the given logger, providing additional context to any logged records.
 200         pub fn from(logger: &'a L, peer_id: Option<PublicKey>, channel_id: Option<ChannelId>, payment_hash: Option<PaymentHash>) -> Self {
 201                 WithContext {
 202                         logger,
 203                         peer_id,
 204                         channel_id,
 205                         payment_hash,
 206                 }
 207         }
 208 }
 209
 210 /// Wrapper for logging a [`PublicKey`] in hex format.
 211 ///
 212 /// This is not exported to bindings users as fmt can't be used in C
 213 #[doc(hidden)]
 214 pub struct DebugPubKey<'a>(pub &'a PublicKey);
 215 impl<'a> core::fmt::Display for DebugPubKey<'a> {
 216         fn fmt(&self, f: &mut core::fmt::Formatter) -> Result<(), core::fmt::Error> {
 217                 for i in self.0.serialize().iter() {
 218                         write!(f, "{:02x}", i)?;
 219                 }
 220                 Ok(())
 221         }
 222 }
 223
 224 /// Wrapper for logging byte slices in hex format.
 225 ///
 226 /// This is not exported to bindings users as fmt can't be used in C
 227 #[doc(hidden)]
 228 pub struct DebugBytes<'a>(pub &'a [u8]);
 229 impl<'a> core::fmt::Display for DebugBytes<'a> {
 230         fn fmt(&self, f: &mut core::fmt::Formatter) -> Result<(), core::fmt::Error> {
 231                 for i in self.0 {
 232                         write!(f, "{:02x}", i)?;
 233                 }
 234                 Ok(())
 235         }
 236 }
 237
 238 /// Wrapper for logging `Iterator`s.
 239 ///
 240 /// This is not exported to bindings users as fmt can't be used in C
 241 #[doc(hidden)]
 242 pub struct DebugIter<T: fmt::Display, I: core::iter::Iterator<Item = T> + Clone>(pub I);
 243 impl<T: fmt::Display, I: core::iter::Iterator<Item = T> + Clone> fmt::Display for DebugIter<T, I> {
 244         fn fmt(&self, f: &mut fmt::Formatter) -> Result<(), fmt::Error> {
 245                 write!(f, "[")?;
 246                 let mut iter = self.0.clone();
 247                 if let Some(item) = iter.next() {
 248                         write!(f, "{}", item)?;
 249                 }
 250                 while let Some(item) = iter.next() {
 251                         write!(f, ", {}", item)?;
 252                 }
 253                 write!(f, "]")?;
 254                 Ok(())
 255         }
 256 }
 257
 258 #[cfg(test)]
 259 mod tests {
 260         use bitcoin::secp256k1::{PublicKey, SecretKey, Secp256k1};
 261         use crate::ln::types::ChannelId;
 262         use crate::ln::PaymentHash;
 263         use crate::util::logger::{Logger, Level, WithContext};
 264         use crate::util::test_utils::TestLogger;
 265         use crate::sync::Arc;
 266
 267         #[test]
 268         fn test_level_show() {
 269                 assert_eq!("INFO", Level::Info.to_string());
 270                 assert_eq!("ERROR", Level::Error.to_string());
 271                 assert_ne!("WARN", Level::Error.to_string());
 272         }
 273
 274         struct WrapperLog {
 275                 logger: Arc<dyn Logger>
 276         }
 277
 278         impl WrapperLog {
 279                 fn new(logger: Arc<dyn Logger>) -> WrapperLog {
 280                         WrapperLog {
 281                                 logger,
 282                         }
 283                 }
 284
 285                 fn call_macros(&self) {
 286                         log_error!(self.logger, "This is an error");
 287                         log_warn!(self.logger, "This is a warning");
 288                         log_info!(self.logger, "This is an info");
 289                         log_debug!(self.logger, "This is a debug");
 290                         log_trace!(self.logger, "This is a trace");
 291                         log_gossip!(self.logger, "This is a gossip");
 292                 }
 293         }
 294
 295         #[test]
 296         fn test_logging_macros() {
 297                 let mut logger = TestLogger::new();
 298                 logger.enable(Level::Gossip);
 299                 let logger : Arc<dyn Logger> = Arc::new(logger);
 300                 let wrapper = WrapperLog::new(Arc::clone(&logger));
 301                 wrapper.call_macros();
 302         }
 303
 304         #[test]
 305         fn test_logging_with_context() {
 306                 let logger = &TestLogger::new();
 307                 let secp_ctx = Secp256k1::new();
 308                 let pk = PublicKey::from_secret_key(&secp_ctx, &SecretKey::from_slice(&[42; 32]).unwrap());
 309                 let payment_hash = PaymentHash([0; 32]);
 310                 let context_logger = WithContext::from(&logger, Some(pk), Some(ChannelId([0; 32])), Some(payment_hash));
 311                 log_error!(context_logger, "This is an error");
 312                 log_warn!(context_logger, "This is an error");
 313                 log_debug!(context_logger, "This is an error");
 314                 log_trace!(context_logger, "This is an error");
 315                 log_gossip!(context_logger, "This is an error");
 316                 log_info!(context_logger, "This is an error");
 317                 logger.assert_log_context_contains(
 318                         "lightning::util::logger::tests", Some(pk), Some(ChannelId([0;32])), 6
 319                 );
 320         }
 321
 322         #[test]
 323         fn test_logging_with_multiple_wrapped_context() {
 324                 let logger = &TestLogger::new();
 325                 let secp_ctx = Secp256k1::new();
 326                 let pk = PublicKey::from_secret_key(&secp_ctx, &SecretKey::from_slice(&[42; 32]).unwrap());
 327                 let payment_hash = PaymentHash([0; 32]);
 328                 let context_logger = &WithContext::from(&logger, None, Some(ChannelId([0; 32])), Some(payment_hash));
 329                 let full_context_logger = WithContext::from(&context_logger, Some(pk), None, None);
 330                 log_error!(full_context_logger, "This is an error");
 331                 log_warn!(full_context_logger, "This is an error");
 332                 log_debug!(full_context_logger, "This is an error");
 333                 log_trace!(full_context_logger, "This is an error");
 334                 log_gossip!(full_context_logger, "This is an error");
 335                 log_info!(full_context_logger, "This is an error");
 336                 logger.assert_log_context_contains(
 337                         "lightning::util::logger::tests", Some(pk), Some(ChannelId([0;32])), 6
 338                 );
 339         }
 340
 341         #[test]
 342         fn test_log_ordering() {
 343                 assert!(Level::Error > Level::Warn);
 344                 assert!(Level::Error >= Level::Warn);
 345                 assert!(Level::Error >= Level::Error);
 346                 assert!(Level::Warn > Level::Info);
 347                 assert!(Level::Warn >= Level::Info);
 348                 assert!(Level::Warn >= Level::Warn);
 349                 assert!(Level::Info > Level::Debug);
 350                 assert!(Level::Info >= Level::Debug);
 351                 assert!(Level::Info >= Level::Info);
 352                 assert!(Level::Debug > Level::Trace);
 353                 assert!(Level::Debug >= Level::Trace);
 354                 assert!(Level::Debug >= Level::Debug);
 355                 assert!(Level::Trace > Level::Gossip);
 356                 assert!(Level::Trace >= Level::Gossip);
 357                 assert!(Level::Trace >= Level::Trace);
 358                 assert!(Level::Gossip >= Level::Gossip);
 359
 360                 assert!(Level::Error <= Level::Error);
 361                 assert!(Level::Warn < Level::Error);
 362                 assert!(Level::Warn <= Level::Error);
 363                 assert!(Level::Warn <= Level::Warn);
 364                 assert!(Level::Info < Level::Warn);
 365                 assert!(Level::Info <= Level::Warn);
 366                 assert!(Level::Info <= Level::Info);
 367                 assert!(Level::Debug < Level::Info);
 368                 assert!(Level::Debug <= Level::Info);
 369                 assert!(Level::Debug <= Level::Debug);
 370                 assert!(Level::Trace < Level::Debug);
 371                 assert!(Level::Trace <= Level::Debug);
 372                 assert!(Level::Trace <= Level::Trace);
 373                 assert!(Level::Gossip < Level::Trace);
 374                 assert!(Level::Gossip <= Level::Trace);
 375                 assert!(Level::Gossip <= Level::Gossip);
 376         }
 377 }