Add peer_id and channel_id explicitly to log records #2314

henghonglee · 2023-05-23T05:16:48Z

This change adds explicit spots in the log Record struct for peer_id and channel_id
This makes the logs much more structured and ensure that they are not forgetten
during implementation

codecov-commenter · 2023-05-23T08:09:29Z

Codecov Report

Attention: 115 lines in your changes are missing coverage. Please review.

Comparison is base (74bc9e2) 88.64% compared to head (35b7688) 88.51%.

❗ Current head 35b7688 differs from pull request most recent head e21a500. Consider uploading reports for the commit e21a500 to get more accurate results

Files	Patch %	Lines
lightning/src/ln/peer_handler.rs	14.49%	50 Missing and 9 partials ⚠️
lightning/src/ln/channelmanager.rs	78.00%	23 Missing and 10 partials ⚠️
lightning/src/chain/chainmonitor.rs	52.77%	7 Missing and 10 partials ⚠️
lightning/src/chain/channelmonitor.rs	93.33%	5 Missing ⚠️
lightning/src/ln/channel.rs	95.00%	0 Missing and 1 partial ⚠️

❗ Your organization needs to install the Codecov GitHub app to enable full functionality.

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #2314      +/-   ##
==========================================
- Coverage   88.64%   88.51%   -0.13%     
==========================================
  Files         115      113       -2     
  Lines       90023    89550     -473     
  Branches    90023    89550     -473     
==========================================
- Hits        79801    79266     -535     
- Misses       7825     7904      +79     
+ Partials     2397     2380      -17

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

TheBlueMatt

Thanks for working on this! Sorry for the delay in getting back to you.

lightning-background-processor/src/lib.rs

lightning/src/util/logger.rs

lightning-invoice/src/utils.rs

lightning/src/chain/channelmonitor.rs

henghonglee · 2023-06-01T11:44:20Z

Probably a crude attempt right now, defining the mappings at the top of the files themselves. would prefer to do all the mapping up front in the mod.rs files or elsewhere and also have a sensible default.

just putting it out there, not feeling too strongly abt this approach yet

lightning-invoice/src/utils.rs

lightning/src/ln/channel.rs

lightning/src/util/macro_logger.rs

TheBlueMatt · 2023-06-05T22:01:45Z

This patch works for me, so I think we should go this kind of direction (with different uses depending on the file for context-containing versions of the log macros):

diff --git a/lightning/src/chain/package.rs b/lightning/src/chain/package.rs
index 4604a164c..6c2c9c706 100644
--- a/lightning/src/chain/package.rs
+++ b/lightning/src/chain/package.rs
@@ -44,4 +44,6 @@ use bitcoin::{PackedLockTime, Sequence, Witness};
 use super::chaininterface::LowerBoundedFeeEstimator;
 
+use crate::util::macro_logger::log_warn;
+
 const MAX_ALLOC_SIZE: usize = 64*1024;
 
diff --git a/lightning/src/ln/channel.rs b/lightning/src/ln/channel.rs
index 99b3c1691..fc9439efa 100644
--- a/lightning/src/ln/channel.rs
+++ b/lightning/src/ln/channel.rs
@@ -53,4 +53,6 @@ use crate::sync::Mutex;
 use bitcoin::hashes::hex::ToHex;
 
+use crate::util::macro_logger::log_warn;
+
 #[cfg(test)]
 pub struct ChannelValueStat {
diff --git a/lightning/src/routing/scoring.rs b/lightning/src/routing/scoring.rs
index 235b1a148..56ebceefb 100644
--- a/lightning/src/routing/scoring.rs
+++ b/lightning/src/routing/scoring.rs
@@ -62,4 +62,5 @@ use crate::routing::router::Path;
 use crate::util::ser::{Readable, ReadableArgs, Writeable, Writer};
 use crate::util::logger::Logger;
+use crate::util::macro_logger::log_warn;
 use crate::util::time::Time;
 
diff --git a/lightning/src/util/macro_logger.rs b/lightning/src/util/macro_logger.rs
index 8742e8e84..42d74767b 100644
--- a/lightning/src/util/macro_logger.rs
+++ b/lightning/src/util/macro_logger.rs
@@ -199,5 +199,5 @@ macro_rules! log_error {
 /// Log at the `WARN` level.
 #[macro_export]
-macro_rules! log_warn {
+macro_rules! _log_warn {
        ($logger: expr, $($arg:tt)*) => (
                $crate::log_given_level!($logger, $crate::util::logger::Level::Warn, $($arg)*);
@@ -205,4 +205,6 @@ macro_rules! log_warn {
 }
 
+pub use _log_warn as log_warn;
+
 /// Log at the `INFO` level.
 #[macro_export]

jkczyz · 2023-11-24T23:09:18Z

Rebased on main from a few days back. Looks like there is some more recent conflicts to resolve. All handle those and will need to go through ChannelManager a little closer.

TheBlueMatt

Just skimmed, but basically LGTM. We might as well land this.

TheBlueMatt · 2023-11-27T23:28:17Z

lightning/src/chain/chainmonitor.rs

@@ -799,12 +808,16 @@ where C::Target: chain::Filter,
 			}
 		};
 		if let ChannelMonitorUpdateStatus::UnrecoverableError = ret {
+			let logger = WithChannelMonitor::from(


Lets move this code lock into the Some match and drop the unwrap?

Yup, refactored the code slightly to allow for this.

TheBlueMatt · 2023-11-27T23:32:48Z

lightning/src/chain/channelmonitor.rs

@@ -1125,6 +1125,30 @@ macro_rules! _process_events_body {
 }
 pub(super) use _process_events_body as process_events_body;

+pub(crate) struct WithChannelMonitor<'a, L: Deref> where L::Target: Logger {


Would be nice to move some of the pub(crate) methods on ChannelMonitor to take a WithChannelMonitor explicitly, rather than a generic Logger, so that we enforce that its called correctly. It can happen later, though. Same in channel.rs, but the channel type.

Yeah, I tend to agree that we should make this more enforceable. Ideally, we can just have those structs store a wrapped Logger instead of passing one and relying on the caller to do the wrapping. Though, I think that may mean introducing a lifetime parameter.

But if instead we make the types explicit on pub(crate) methods, then we may avoid some redundant wrapping. Let me take a look.

jkczyz · 2023-11-28T17:31:29Z

Pushed a few fixups and I think an amended commit that I hadn't pushed last week.

jkczyz · 2023-11-28T17:32:55Z

Pushed a few fixups and I think an amended commit that I hadn't pushed last week.

Ugh, also a rebase apparently 😞

jkczyz · 2023-11-28T17:41:28Z

Ugh, also a rebase apparently 😞

Just a bad push, actually. This should be the right diff: https://github.com/lightningdevkit/rust-lightning/compare/35b768825950c81bee510d2a80cd19c926b817a6..189ea78eca81e86e3be9d561eaf005e669a7d51e

jkczyz · 2023-11-29T16:59:59Z

@TheBlueMatt Looks like I'll need to rebase this again.

TheBlueMatt · 2023-12-01T00:09:44Z

I'm kinda ready to land whenever you want to squash and rebase, will just take me an hour to go back over it and hit the button.

TheBlueMatt · 2023-12-01T17:27:57Z

Ugh, needs rebase again lol

Instead of passing a reference to a Record, pass the Logger an owned Record so that it can be decorated with semantic context.

Include optional peer and channel ids to logger::Record. This will be used by wrappers around Logger in order to provide more context (e.g., the peer that sent a message, the channel an operation is pertaining to, etc.). Implementations of Logger can include this as metadata to aid in searching logs.

Using a decorator pattern, add peer_id and channel_id to Record stored on Logger.

Move the handling of ChannelMonitorUpdateStatus::UnrecoverableError to the point of error to avoid needing an unwrap later when re-wrapping the logger.

jkczyz · 2023-12-01T17:56:32Z

Ugh, needs rebase again lol

Rebased!

TheBlueMatt

Some followups, but we need to just land this so that we can move on.

TheBlueMatt · 2023-12-01T19:23:12Z

lightning/src/util/test_utils.rs

+		&self, module: &str, peer_id: Option<PublicKey>, channel_id: Option<ChannelId>, count: usize
+	) {
+		let context_entries = self.context.lock().unwrap();
+		let l: usize = context_entries.iter()


Its a hashmap, we can look up, rather than iterate + count.

TheBlueMatt · 2023-12-01T21:07:43Z

lightning/src/ln/channel.rs

+	}
+}
+
+impl<'a, 'b, L: Deref> WithChannelContext<'a, L>


I believe 'b can be elided.

TheBlueMatt · 2023-12-01T21:10:08Z

lightning/src/chain/channelmonitor.rs

+	}
+}
+
+impl<'a, 'b, L: Deref> WithChannelMonitor<'a, L> where L::Target: Logger {


I believe 'b can be elided.

TheBlueMatt · 2023-12-02T17:43:06Z

lightning/src/chain/chainmonitor.rs

+					ChannelMonitorUpdateStatus::UnrecoverableError => {
+						// Take the monitors lock for writing so that we poison it and any future
+						// operations going forward fail immediately.
+						core::mem::drop(monitors);


Because this no longer drops the lock itself, we'll just hang on the next line rather than actually panicking.

Post-#2314 Cleanups #3

Post-#2314 Cleanups

henghonglee force-pushed the issue-2292 branch from 66313f7 to 14f187c Compare May 23, 2023 06:46

henghonglee force-pushed the issue-2292 branch 3 times, most recently from bdf0de5 to 2c69caf Compare May 24, 2023 22:00

henghonglee marked this pull request as ready for review May 24, 2023 22:00

henghonglee force-pushed the issue-2292 branch 4 times, most recently from 8bb0617 to 8748f91 Compare May 24, 2023 22:09

TheBlueMatt reviewed May 30, 2023

View reviewed changes

lightning-background-processor/src/lib.rs Outdated Show resolved Hide resolved

lightning/src/util/logger.rs Outdated Show resolved Hide resolved

lightning-invoice/src/utils.rs Outdated Show resolved Hide resolved

lightning/src/chain/channelmonitor.rs Outdated Show resolved Hide resolved

henghonglee closed this Jun 1, 2023

henghonglee force-pushed the issue-2292 branch 2 times, most recently from 377116a to 32eb894 Compare June 1, 2023 09:49

henghonglee reopened this Jun 1, 2023

henghonglee force-pushed the issue-2292 branch 4 times, most recently from 8515d27 to 4f941bc Compare June 1, 2023 11:41

henghonglee commented Jun 1, 2023

View reviewed changes

lightning-invoice/src/utils.rs Outdated Show resolved Hide resolved

henghonglee force-pushed the issue-2292 branch from 4f941bc to 4fe78af Compare June 1, 2023 11:52

TheBlueMatt reviewed Jun 5, 2023

View reviewed changes

lightning/src/ln/channel.rs Outdated Show resolved Hide resolved

lightning/src/util/macro_logger.rs Outdated Show resolved Hide resolved

henghonglee force-pushed the issue-2292 branch 6 times, most recently from 062c703 to da9f77c Compare June 6, 2023 04:49

jkczyz force-pushed the issue-2292 branch from c5648f2 to 35b7688 Compare November 25, 2023 04:02

TheBlueMatt reviewed Nov 27, 2023

View reviewed changes

jkczyz force-pushed the issue-2292 branch from 35b7688 to c5648f2 Compare November 28, 2023 17:30

jkczyz force-pushed the issue-2292 branch from c5648f2 to 189ea78 Compare November 28, 2023 17:39

jkczyz force-pushed the issue-2292 branch from 523fc6d to 8776c1e Compare December 1, 2023 00:14

henghonglee and others added 9 commits December 1, 2023 11:30

Pass Record by value to Logger

0cba31f

Instead of passing a reference to a Record, pass the Logger an owned Record so that it can be decorated with semantic context.

Add WithContext and Tests

973636b

Add WithChannelDetails

fa7f2f4

Add WithChannelContext

aa502fe

Add WithChannelMonitor

a727cca

Use wrapper to add context to logging

df3ab2e

Using a decorator pattern, add peer_id and channel_id to Record stored on Logger.

Remove unused handle_error macro rule

e6d8f35

Refactor ChainMonitor::update_channel error case

e21a500

Move the handling of ChannelMonitorUpdateStatus::UnrecoverableError to the point of error to avoid needing an unwrap later when re-wrapping the logger.

jkczyz force-pushed the issue-2292 branch from 8776c1e to e21a500 Compare December 1, 2023 17:56

TheBlueMatt approved these changes Dec 2, 2023

View reviewed changes

TheBlueMatt merged commit 6b43153 into lightningdevkit:main Dec 2, 2023
15 checks passed

TheBlueMatt mentioned this pull request Dec 3, 2023

Post-#2314 Cleanups #3 #2769

Merged

wpaulino added a commit that referenced this pull request Dec 4, 2023

Merge pull request #2769 from TheBlueMatt/2023-12-2314-cleanups-3

4d66cce

Post-#2314 Cleanups #3

jkczyz mentioned this pull request Dec 6, 2023

Post-#2314 Cleanups #2765

Merged

TheBlueMatt added a commit that referenced this pull request Dec 6, 2023

Merge pull request #2765 from TheBlueMatt/2023-12-2314-cleanups-1

fcf47a4

Post-#2314 Cleanups

valentinewallace mentioned this pull request Dec 7, 2023

Improve block connection logging and filtered txids #2637

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add peer_id and channel_id explicitly to log records #2314

Add peer_id and channel_id explicitly to log records #2314

henghonglee commented May 23, 2023 •

edited

Loading

codecov-commenter commented May 23, 2023 •

edited

Loading

TheBlueMatt left a comment

henghonglee commented Jun 1, 2023 •

edited

Loading

TheBlueMatt commented Jun 5, 2023

jkczyz commented Nov 24, 2023

TheBlueMatt left a comment

TheBlueMatt Nov 27, 2023

jkczyz Nov 29, 2023

TheBlueMatt Nov 27, 2023

jkczyz Nov 28, 2023

jkczyz commented Nov 28, 2023

jkczyz commented Nov 28, 2023

jkczyz commented Nov 28, 2023

jkczyz commented Nov 29, 2023

TheBlueMatt commented Dec 1, 2023

TheBlueMatt commented Dec 1, 2023

jkczyz commented Dec 1, 2023

TheBlueMatt left a comment

TheBlueMatt Dec 1, 2023

TheBlueMatt Dec 1, 2023

TheBlueMatt Dec 1, 2023

TheBlueMatt Dec 2, 2023

Add peer_id and channel_id explicitly to log records #2314

Add peer_id and channel_id explicitly to log records #2314

Conversation

henghonglee commented May 23, 2023 • edited Loading

codecov-commenter commented May 23, 2023 • edited Loading

Codecov Report

TheBlueMatt left a comment

Choose a reason for hiding this comment

henghonglee commented Jun 1, 2023 • edited Loading

TheBlueMatt commented Jun 5, 2023

jkczyz commented Nov 24, 2023

TheBlueMatt left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jkczyz commented Nov 28, 2023

jkczyz commented Nov 28, 2023

jkczyz commented Nov 28, 2023

jkczyz commented Nov 29, 2023

TheBlueMatt commented Dec 1, 2023

TheBlueMatt commented Dec 1, 2023

jkczyz commented Dec 1, 2023

TheBlueMatt left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

henghonglee commented May 23, 2023 •

edited

Loading

codecov-commenter commented May 23, 2023 •

edited

Loading

henghonglee commented Jun 1, 2023 •

edited

Loading