Do not log_debug when we receive duplicate gossip messages

We very often receive duplicate gossip messages, which now causes us
to log at the DEBUG level, which is almost certainly not what a
user wants. Instead, we add a new form of ErrorAction which causes
us to only log at the TRACE level.

diff --git a/lightning/src/ln/msgs.rs b/lightning/src/ln/msgs.rs
index f02a478357b8c32598ad5c4096abe905482d5c8e..c45e2277fb8db5a307a2b0c13fb546d97d62ec74 100644 (file)
--- a/lightning/src/ln/msgs.rs
+++ b/lightning/src/ln/msgs.rs
@@ -38,6 +38,7 @@ use core::fmt::Debug;
 use std::io::Read;
 
 use util::events::MessageSendEventsProvider;
+use util::logger;
 use util::ser::{Readable, Writeable, Writer, FixedLengthReader, HighZeroBytesDroppedVarInt};
 
 use ln::{PaymentPreimage, PaymentHash, PaymentSecret};
@@ -688,7 +689,11 @@ pub enum ErrorAction {
                msg: Option<ErrorMessage>
        },
        /// The peer did something harmless that we weren't able to process, just log and ignore
+       // New code should *not* use this. New code must use IgnoreAndLog, below!
        IgnoreError,
+       /// The peer did something harmless that we weren't able to meaningfully process.
+       /// If the error is logged, log it at the given level.
+       IgnoreAndLog(logger::Level),
        /// The peer did something incorrect. Tell them.
        SendErrorMessage {
                /// The message to send.

diff --git a/lightning/src/ln/peer_handler.rs b/lightning/src/ln/peer_handler.rs
index 5fab2c6009c6ceec7a801fc3c9e5420053e1a491..78ffcfd1de522d7c84eeefe347e1671ee3f50a88 100644 (file)
--- a/lightning/src/ln/peer_handler.rs
+++ b/lightning/src/ln/peer_handler.rs
@@ -27,7 +27,7 @@ use ln::wire;
 use ln::wire::Encode;
 use util::byte_utils;
 use util::events::{MessageSendEvent, MessageSendEventsProvider};
-use util::logger::Logger;
+use util::logger::{Logger, Level};
 use routing::network_graph::NetGraphMsgHandler;
 
 use prelude::*;
@@ -717,15 +717,19 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref> PeerManager<D
                                                                                        match e.action {
                                                                                                msgs::ErrorAction::DisconnectPeer { msg: _ } => {
                                                                                                        //TODO: Try to push msg
-                                                                                                       log_debug!(self.logger, "Got Err handling message, disconnecting peer with: {}", e.err);
+                                                                                                       log_debug!(self.logger, "Error handling message; disconnecting peer with: {}", e.err);
                                                                                                        return Err(PeerHandleError{ no_connection_possible: false });
                                                                                                },
+                                                                                               msgs::ErrorAction::IgnoreAndLog(level) => {
+                                                                                                       log_given_level!(self.logger, level, "Error handling message; ignoring: {}", e.err);
+                                                                                                       continue
+                                                                                               },
                                                                                                msgs::ErrorAction::IgnoreError => {
-                                                                                                       log_debug!(self.logger, "Got ignored error handling message: {}", e.err);
+                                                                                                       log_debug!(self.logger, "Error handling message; ignoring: {}", e.err);
                                                                                                        continue;
                                                                                                },
                                                                                                msgs::ErrorAction::SendErrorMessage { msg } => {
-                                                                                                       log_debug!(self.logger, "Got Err handling message, sending Error message with: {}", e.err);
+                                                                                                       log_debug!(self.logger, "Error handling message; sending error message with: {}", e.err);
                                                                                                        self.enqueue_message(peer, &msg);
                                                                                                        continue;
                                                                                                },
@@ -1284,7 +1288,12 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref> PeerManager<D
                                                                        self.message_handler.chan_handler.peer_disconnected(&node_id, false);
                                                                }
                                                        },
-                                                       msgs::ErrorAction::IgnoreError => {},
+                                                       msgs::ErrorAction::IgnoreAndLog(level) => {
+                                                               log_given_level!(self.logger, level, "Received a HandleError event to be ignored for node {}", log_pubkey!(node_id));
+                                                       },
+                                                       msgs::ErrorAction::IgnoreError => {
+                                                               log_debug!(self.logger, "Received a HandleError event to be ignored for node {}", log_pubkey!(node_id));
+                                                       },
                                                        msgs::ErrorAction::SendErrorMessage { ref msg } => {
                                                                log_trace!(self.logger, "Handling SendErrorMessage HandleError event in peer_handler for node {} with message {}",
                                                                                log_pubkey!(node_id),

diff --git a/lightning/src/routing/network_graph.rs b/lightning/src/routing/network_graph.rs
index 2c55d0a1d525c7f16450983698f120109a0843fc..6fe8912bd16a66bd651ee99e6191fb300cb9031d 100644 (file)
--- a/lightning/src/routing/network_graph.rs
+++ b/lightning/src/routing/network_graph.rs
@@ -28,7 +28,7 @@ use ln::msgs::{ChannelAnnouncement, ChannelUpdate, NodeAnnouncement, OptionalFie
 use ln::msgs::{QueryChannelRange, ReplyChannelRange, QueryShortChannelIds, ReplyShortChannelIdsEnd};
 use ln::msgs;
 use util::ser::{Writeable, Readable, Writer};
-use util::logger::Logger;
+use util::logger::{Logger, Level};
 use util::events::{MessageSendEvent, MessageSendEventsProvider};
 use util::scid_utils::{block_from_scid, scid_from_parts, MAX_SCID_BLOCK};
 
@@ -717,7 +717,7 @@ impl NetworkGraph {
                        Some(node) => {
                                if let Some(node_info) = node.announcement_info.as_ref() {
                                        if node_info.last_update  >= msg.timestamp {
-                                               return Err(LightningError{err: "Update older than last processed update".to_owned(), action: ErrorAction::IgnoreError});
+                                               return Err(LightningError{err: "Update older than last processed update".to_owned(), action: ErrorAction::IgnoreAndLog(Level::Trace)});
                                        }
                                }
 
@@ -838,7 +838,7 @@ impl NetworkGraph {
                                        Self::remove_channel_in_nodes(&mut self.nodes, &entry.get(), msg.short_channel_id);
                                        *entry.get_mut() = chan_info;
                                } else {
-                                       return Err(LightningError{err: "Already have knowledge of channel".to_owned(), action: ErrorAction::IgnoreError})
+                                       return Err(LightningError{err: "Already have knowledge of channel".to_owned(), action: ErrorAction::IgnoreAndLog(Level::Trace)})
                                }
                        },
                        BtreeEntry::Vacant(entry) => {
@@ -940,7 +940,7 @@ impl NetworkGraph {
                                        ( $target: expr, $src_node: expr) => {
                                                if let Some(existing_chan_info) = $target.as_ref() {
                                                        if existing_chan_info.last_update >= msg.timestamp {
-                                                               return Err(LightningError{err: "Update older than last processed update".to_owned(), action: ErrorAction::IgnoreError});
+                                                               return Err(LightningError{err: "Update older than last processed update".to_owned(), action: ErrorAction::IgnoreAndLog(Level::Trace)});
                                                        }
                                                        chan_was_enabled = existing_chan_info.enabled;
                                                } else {