Make peers sending gossip out of order logging less scary
authorMatt Corallo <git@bluematt.me>
Tue, 13 Feb 2024 22:57:18 +0000 (22:57 +0000)
committerMatt Corallo <git@bluematt.me>
Tue, 13 Feb 2024 23:06:38 +0000 (23:06 +0000)
Multiple times we've had users wonder why they see `Error handling
message from.*; ignoring: Couldn't find channel for update` in
their logs and wonder if its related to their channel
force-closing. While this does indicate a peer is sending us gossip
our of order (and thus misbehaving), its not relevant to channel
operation and the logged message and level should indicate that.

Thus, here, we move the level to Gossip and add "gossip" between
"handling" and "message" (so it reads "Error handling gossip
message from.*").

Fixes #2471

lightning/src/ln/peer_handler.rs
lightning/src/routing/gossip.rs

index 0f206117ec676abbc0b4123fac756c68802eccdd..8d83763715c83326b61cdf83f2faeec6f721d795 100644 (file)
@@ -33,7 +33,7 @@ use crate::onion_message::offers::{OffersMessage, OffersMessageHandler};
 use crate::onion_message::packet::OnionMessageContents;
 use crate::routing::gossip::{NodeId, NodeAlias};
 use crate::util::atomic_counter::AtomicCounter;
-use crate::util::logger::{Logger, WithContext};
+use crate::util::logger::{Level, Logger, WithContext};
 use crate::util::string::PrintableString;
 
 use crate::prelude::*;
@@ -1329,7 +1329,9 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, OM: Deref, L: Deref, CM
                                                                                        return Err(PeerHandleError { });
                                                                                },
                                                                                msgs::ErrorAction::IgnoreAndLog(level) => {
-                                                                                       log_given_level!(logger, level, "Error handling message{}; ignoring: {}", OptionalFromDebugger(&peer_node_id), e.err);
+                                                                                       log_given_level!(logger, level, "Error handling {}message{}; ignoring: {}",
+                                                                                               if level == Level::Gossip { "gossip " } else { "" },
+                                                                                               OptionalFromDebugger(&peer_node_id), e.err);
                                                                                        continue
                                                                                },
                                                                                msgs::ErrorAction::IgnoreDuplicateGossip => continue, // Don't even bother logging these
index 950ec79a1e98e19e8d31da31624227ddca07832a..a4938f72e8b6fd9b6eee819ebe307c30c176e1e3 100644 (file)
@@ -1925,7 +1925,10 @@ impl<L: Deref> NetworkGraph<L> where L::Target: Logger {
                        None => {
                                core::mem::drop(channels);
                                self.pending_checks.check_hold_pending_channel_update(msg, full_msg)?;
-                               return Err(LightningError{err: "Couldn't find channel for update".to_owned(), action: ErrorAction::IgnoreError});
+                               return Err(LightningError {
+                                       err: "Couldn't find channel for update".to_owned(),
+                                       action: ErrorAction::IgnoreAndLog(Level::Gossip),
+                               });
                        },
                        Some(channel) => {
                                if msg.htlc_maximum_msat > MAX_VALUE_MSAT {