Merge pull request #1352 from TheBlueMatt/2022-03-debug-rwlock
[rust-lightning] / lightning / src / ln / peer_handler.rs
index 0dbad0a311a1794b5f811259785768936dc2dda4..d3ac2ebe9a39bf2e918f58dbf4d012ac0434ae99 100644 (file)
@@ -24,16 +24,16 @@ use ln::channelmanager::{SimpleArcChannelManager, SimpleRefChannelManager};
 use util::ser::{VecWriter, Writeable, Writer};
 use ln::peer_channel_encryptor::{PeerChannelEncryptor,NextNoiseStep};
 use ln::wire;
-use util::byte_utils;
+use ln::wire::Encode;
+use util::atomic_counter::AtomicCounter;
 use util::events::{MessageSendEvent, MessageSendEventsProvider};
 use util::logger::Logger;
-use routing::network_graph::NetGraphMsgHandler;
+use routing::network_graph::{NetworkGraph, NetGraphMsgHandler};
 
 use prelude::*;
 use io;
 use alloc::collections::LinkedList;
 use sync::{Arc, Mutex};
-use core::sync::atomic::{AtomicUsize, Ordering};
 use core::{cmp, hash, fmt, mem};
 use core::ops::Deref;
 use core::convert::Infallible;
@@ -307,12 +307,12 @@ const OUTBOUND_BUFFER_LIMIT_DROP_GOSSIP: usize = OUTBOUND_BUFFER_LIMIT_READ_PAUS
 /// Thus, to avoid needlessly disconnecting a peer, we allow a peer to take this many timer ticks
 /// per connected peer to respond to a ping, as long as they send us at least one message during
 /// each tick, ensuring we aren't actually just disconnected.
-/// With a timer tick interval of five seconds, this translates to about 30 seconds per connected
+/// With a timer tick interval of ten seconds, this translates to about 40 seconds per connected
 /// peer.
 ///
 /// When we improve parallelism somewhat we should reduce this to e.g. this many timer ticks per
 /// two connected peers, assuming most LDK-running systems have at least two cores.
-const MAX_BUFFER_DRAIN_TICK_INTERVALS_PER_PEER: i8 = 6;
+const MAX_BUFFER_DRAIN_TICK_INTERVALS_PER_PEER: i8 = 4;
 
 /// This is the minimum number of messages we expect a peer to be able to handle within one timer
 /// tick. Once we have sent this many messages since the last ping, we send a ping right away to
@@ -371,18 +371,12 @@ struct PeerHolder<Descriptor: SocketDescriptor> {
        node_id_to_descriptor: HashMap<PublicKey, Descriptor>,
 }
 
-#[cfg(not(any(target_pointer_width = "32", target_pointer_width = "64")))]
-fn _check_usize_is_32_or_64() {
-       // See below, less than 32 bit pointers may be unsafe here!
-       unsafe { mem::transmute::<*const usize, [u8; 4]>(panic!()); }
-}
-
 /// SimpleArcPeerManager is useful when you need a PeerManager with a static lifetime, e.g.
 /// when you're using lightning-net-tokio (since tokio::spawn requires parameters with static
 /// lifetimes). Other times you can afford a reference, which is more efficient, in which case
 /// SimpleRefPeerManager is the more appropriate type. Defining these type aliases prevents
 /// issues such as overly long function definitions.
-pub type SimpleArcPeerManager<SD, M, T, F, C, L> = PeerManager<SD, Arc<SimpleArcChannelManager<M, T, F, L>>, Arc<NetGraphMsgHandler<Arc<C>, Arc<L>>>, Arc<L>, Arc<IgnoringMessageHandler>>;
+pub type SimpleArcPeerManager<SD, M, T, F, C, L> = PeerManager<SD, Arc<SimpleArcChannelManager<M, T, F, L>>, Arc<NetGraphMsgHandler<Arc<NetworkGraph>, Arc<C>, Arc<L>>>, Arc<L>, Arc<IgnoringMessageHandler>>;
 
 /// SimpleRefPeerManager is a type alias for a PeerManager reference, and is the reference
 /// counterpart to the SimpleArcPeerManager type alias. Use this type by default when you don't
@@ -390,7 +384,7 @@ pub type SimpleArcPeerManager<SD, M, T, F, C, L> = PeerManager<SD, Arc<SimpleArc
 /// usage of lightning-net-tokio (since tokio::spawn requires parameters with static lifetimes).
 /// But if this is not necessary, using a reference is more efficient. Defining these type aliases
 /// helps with issues such as long function definitions.
-pub type SimpleRefPeerManager<'a, 'b, 'c, 'd, 'e, 'f, 'g, SD, M, T, F, C, L> = PeerManager<SD, SimpleRefChannelManager<'a, 'b, 'c, 'd, 'e, M, T, F, L>, &'e NetGraphMsgHandler<&'g C, &'f L>, &'f L, IgnoringMessageHandler>;
+pub type SimpleRefPeerManager<'a, 'b, 'c, 'd, 'e, 'f, 'g, 'h, SD, M, T, F, C, L> = PeerManager<SD, SimpleRefChannelManager<'a, 'b, 'c, 'd, 'e, M, T, F, L>, &'e NetGraphMsgHandler<&'g NetworkGraph, &'h C, &'f L>, &'f L, IgnoringMessageHandler>;
 
 /// A PeerManager manages a set of peers, described by their [`SocketDescriptor`] and marshalls
 /// socket events into messages which it passes on to its [`MessageHandler`].
@@ -422,10 +416,7 @@ pub struct PeerManager<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: De
        ephemeral_key_midstate: Sha256Engine,
        custom_message_handler: CMH,
 
-       // Usize needs to be at least 32 bits to avoid overflowing both low and high. If usize is 64
-       // bits we will never realistically count into high:
-       peer_counter_low: AtomicUsize,
-       peer_counter_high: AtomicUsize,
+       peer_counter: AtomicCounter,
 
        logger: L,
 }
@@ -493,6 +484,17 @@ impl<Descriptor: SocketDescriptor, RM: Deref, L: Deref> PeerManager<Descriptor,
        }
 }
 
+/// A simple wrapper that optionally prints " from <pubkey>" for an optional pubkey.
+/// This works around `format!()` taking a reference to each argument, preventing
+/// `if let Some(node_id) = peer.their_node_id { format!(.., node_id) } else { .. }` from compiling
+/// due to lifetime errors.
+struct OptionalFromDebugger<'a>(&'a Option<PublicKey>);
+impl core::fmt::Display for OptionalFromDebugger<'_> {
+       fn fmt(&self, f: &mut core::fmt::Formatter<'_>) -> Result<(), core::fmt::Error> {
+               if let Some(node_id) = self.0 { write!(f, " from {}", log_pubkey!(node_id)) } else { Ok(()) }
+       }
+}
+
 impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> PeerManager<Descriptor, CM, RM, L, CMH> where
                CM::Target: ChannelMessageHandler,
                RM::Target: RoutingMessageHandler,
@@ -513,8 +515,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                        }),
                        our_node_secret,
                        ephemeral_key_midstate,
-                       peer_counter_low: AtomicUsize::new(0),
-                       peer_counter_high: AtomicUsize::new(0),
+                       peer_counter: AtomicCounter::new(),
                        logger,
                        custom_message_handler,
                }
@@ -537,14 +538,8 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
 
        fn get_ephemeral_key(&self) -> SecretKey {
                let mut ephemeral_hash = self.ephemeral_key_midstate.clone();
-               let low = self.peer_counter_low.fetch_add(1, Ordering::AcqRel);
-               let high = if low == 0 {
-                       self.peer_counter_high.fetch_add(1, Ordering::AcqRel)
-               } else {
-                       self.peer_counter_high.load(Ordering::Acquire)
-               };
-               ephemeral_hash.input(&byte_utils::le64_to_array(low as u64));
-               ephemeral_hash.input(&byte_utils::le64_to_array(high as u64));
+               let counter = self.peer_counter.get_increment();
+               ephemeral_hash.input(&counter.to_le_bytes());
                SecretKey::from_slice(&Sha256::from_engine(ephemeral_hash).into_inner()).expect("You broke SHA-256!")
        }
 
@@ -763,7 +758,12 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
        fn enqueue_message<M: wire::Type>(&self, peer: &mut Peer, message: &M) {
                let mut buffer = VecWriter(Vec::with_capacity(2048));
                wire::write(message, &mut buffer).unwrap(); // crash if the write failed
-               log_trace!(self.logger, "Enqueueing message {:?} to {}", message, log_pubkey!(peer.their_node_id.unwrap()));
+
+               if is_gossip_msg(message.type_id()) {
+                       log_gossip!(self.logger, "Enqueueing message {:?} to {}", message, log_pubkey!(peer.their_node_id.unwrap()));
+               } else {
+                       log_trace!(self.logger, "Enqueueing message {:?} to {}", message, log_pubkey!(peer.their_node_id.unwrap()))
+               }
                self.enqueue_encoded_message(peer, &buffer.0);
        }
 
@@ -804,19 +804,25 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                                                                        match e.action {
                                                                                                msgs::ErrorAction::DisconnectPeer { msg: _ } => {
                                                                                                        //TODO: Try to push msg
-                                                                                                       log_debug!(self.logger, "Error handling message; disconnecting peer with: {}", e.err);
+                                                                                                       log_debug!(self.logger, "Error handling message{}; disconnecting peer with: {}", OptionalFromDebugger(&peer.their_node_id), 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);
+                                                                                                       log_given_level!(self.logger, level, "Error handling message{}; ignoring: {}", OptionalFromDebugger(&peer.their_node_id), e.err);
                                                                                                        continue
                                                                                                },
+                                                                                               msgs::ErrorAction::IgnoreDuplicateGossip => continue, // Don't even bother logging these
                                                                                                msgs::ErrorAction::IgnoreError => {
-                                                                                                       log_debug!(self.logger, "Error handling message; ignoring: {}", e.err);
+                                                                                                       log_debug!(self.logger, "Error handling message{}; ignoring: {}", OptionalFromDebugger(&peer.their_node_id), e.err);
                                                                                                        continue;
                                                                                                },
                                                                                                msgs::ErrorAction::SendErrorMessage { msg } => {
-                                                                                                       log_debug!(self.logger, "Error handling message; sending error message with: {}", e.err);
+                                                                                                       log_debug!(self.logger, "Error handling message{}; sending error message with: {}", OptionalFromDebugger(&peer.their_node_id), e.err);
+                                                                                                       self.enqueue_message(peer, &msg);
+                                                                                                       continue;
+                                                                                               },
+                                                                                               msgs::ErrorAction::SendWarningMessage { msg, log_level } => {
+                                                                                                       log_given_level!(self.logger, log_level, "Error handling message{}; sending warning message with: {}", OptionalFromDebugger(&peer.their_node_id), e.err);
                                                                                                        self.enqueue_message(peer, &msg);
                                                                                                        continue;
                                                                                                },
@@ -860,6 +866,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                                                        let features = InitFeatures::known();
                                                                        let resp = msgs::Init { features };
                                                                        self.enqueue_message(peer, &resp);
+                                                                       peer.awaiting_pong_timer_tick_intervals = 0;
                                                                },
                                                                NextNoiseStep::ActThree => {
                                                                        let their_node_id = try_potential_handleerror!(peer.channel_encryptor.process_act_three(&peer.pending_read_buffer[..]));
@@ -870,6 +877,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                                                        let features = InitFeatures::known();
                                                                        let resp = msgs::Init { features };
                                                                        self.enqueue_message(peer, &resp);
+                                                                       peer.awaiting_pong_timer_tick_intervals = 0;
                                                                },
                                                                NextNoiseStep::NoiseComplete => {
                                                                        if peer.pending_read_is_header {
@@ -894,25 +902,40 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                                                                        Ok(x) => x,
                                                                                        Err(e) => {
                                                                                                match e {
-                                                                                                       msgs::DecodeError::UnknownVersion => return Err(PeerHandleError { no_connection_possible: false }),
-                                                                                                       msgs::DecodeError::UnknownRequiredFeature => {
-                                                                                                               log_trace!(self.logger, "Got a channel/node announcement with an known required feature flag, you may want to update!");
+                                                                                                       // Note that to avoid recursion we never call
+                                                                                                       // `do_attempt_write_data` from here, causing
+                                                                                                       // the messages enqueued here to not actually
+                                                                                                       // be sent before the peer is disconnected.
+                                                                                                       (msgs::DecodeError::UnknownRequiredFeature, Some(ty)) if is_gossip_msg(ty) => {
+                                                                                                               log_gossip!(self.logger, "Got a channel/node announcement with an unknown required feature flag, you may want to update!");
+                                                                                                               continue;
+                                                                                                       }
+                                                                                                       (msgs::DecodeError::UnsupportedCompression, _) => {
+                                                                                                               log_gossip!(self.logger, "We don't support zlib-compressed message fields, sending a warning and ignoring message");
+                                                                                                               self.enqueue_message(peer, &msgs::WarningMessage { channel_id: [0; 32], data: "Unsupported message compression: zlib".to_owned() });
                                                                                                                continue;
                                                                                                        }
-                                                                                                       msgs::DecodeError::InvalidValue => {
+                                                                                                       (_, Some(ty)) if is_gossip_msg(ty) => {
+                                                                                                               log_gossip!(self.logger, "Got an invalid value while deserializing a gossip message");
+                                                                                                               self.enqueue_message(peer, &msgs::WarningMessage { channel_id: [0; 32], data: "Unreadable/bogus gossip message".to_owned() });
+                                                                                                               continue;
+                                                                                                       }
+                                                                                                       (msgs::DecodeError::UnknownRequiredFeature, ty) => {
+                                                                                                               log_gossip!(self.logger, "Received a message with an unknown required feature flag or TLV, you may want to update!");
+                                                                                                               self.enqueue_message(peer, &msgs::WarningMessage { channel_id: [0; 32], data: format!("Received an unknown required feature/TLV in message type {:?}", ty) });
+                                                                                                               return Err(PeerHandleError { no_connection_possible: false });
+                                                                                                       }
+                                                                                                       (msgs::DecodeError::UnknownVersion, _) => return Err(PeerHandleError { no_connection_possible: false }),
+                                                                                                       (msgs::DecodeError::InvalidValue, _) => {
                                                                                                                log_debug!(self.logger, "Got an invalid value while deserializing message");
                                                                                                                return Err(PeerHandleError { no_connection_possible: false });
                                                                                                        }
-                                                                                                       msgs::DecodeError::ShortRead => {
+                                                                                                       (msgs::DecodeError::ShortRead, _) => {
                                                                                                                log_debug!(self.logger, "Deserialization failed due to shortness of message");
                                                                                                                return Err(PeerHandleError { no_connection_possible: false });
                                                                                                        }
-                                                                                                       msgs::DecodeError::BadLengthDescriptor => return Err(PeerHandleError { no_connection_possible: false }),
-                                                                                                       msgs::DecodeError::Io(_) => return Err(PeerHandleError { no_connection_possible: false }),
-                                                                                                       msgs::DecodeError::UnsupportedCompression => {
-                                                                                                               log_trace!(self.logger, "We don't support zlib-compressed message fields, ignoring message");
-                                                                                                               continue;
-                                                                                                       }
+                                                                                                       (msgs::DecodeError::BadLengthDescriptor, _) => return Err(PeerHandleError { no_connection_possible: false }),
+                                                                                                       (msgs::DecodeError::Io(_), _) => return Err(PeerHandleError { no_connection_possible: false }),
                                                                                                }
                                                                                        }
                                                                                };
@@ -957,7 +980,12 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                peer: &mut Peer,
                message: wire::Message<<<CMH as core::ops::Deref>::Target as wire::CustomMessageReader>::CustomMessage>
        ) -> Result<Option<wire::Message<<<CMH as core::ops::Deref>::Target as wire::CustomMessageReader>::CustomMessage>>, MessageHandlingError> {
-               log_trace!(self.logger, "Received message {:?} from {}", message, log_pubkey!(peer.their_node_id.unwrap()));
+               if is_gossip_msg(message.type_id()) {
+                       log_gossip!(self.logger, "Received message {:?} from {}", message, log_pubkey!(peer.their_node_id.unwrap()));
+               } else {
+                       log_trace!(self.logger, "Received message {:?} from {}", message, log_pubkey!(peer.their_node_id.unwrap()));
+               }
+
                peer.received_message_since_timer_tick = true;
 
                // Need an Init as first message
@@ -980,7 +1008,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                        return Err(PeerHandleError{ no_connection_possible: false }.into());
                                }
 
-                               log_info!(self.logger, "Received peer Init message: {}", msg.features);
+                               log_info!(self.logger, "Received peer Init message from {}: {}", log_pubkey!(peer.their_node_id.unwrap()), msg.features);
 
                                if msg.features.initial_routing_sync() {
                                        peer.sync_status = InitSyncTracker::ChannelsSyncing(0);
@@ -1014,6 +1042,21 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                        return Err(PeerHandleError{ no_connection_possible: true }.into());
                                }
                        },
+                       wire::Message::Warning(msg) => {
+                               let mut data_is_printable = true;
+                               for b in msg.data.bytes() {
+                                       if b < 32 || b > 126 {
+                                               data_is_printable = false;
+                                               break;
+                                       }
+                               }
+
+                               if data_is_printable {
+                                       log_debug!(self.logger, "Got warning message from {}: {}", log_pubkey!(peer.their_node_id.unwrap()), msg.data);
+                               } else {
+                                       log_debug!(self.logger, "Got warning message from {} with non-ASCII error message", log_pubkey!(peer.their_node_id.unwrap()));
+                               }
+                       },
 
                        wire::Message::Ping(msg) => {
                                if msg.ponglen < 65532 {
@@ -1136,7 +1179,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
        fn forward_broadcast_msg(&self, peers: &mut PeerHolder<Descriptor>, msg: &wire::Message<<<CMH as core::ops::Deref>::Target as wire::CustomMessageReader>::CustomMessage>, except_node: Option<&PublicKey>) {
                match msg {
                        wire::Message::ChannelAnnouncement(ref msg) => {
-                               log_trace!(self.logger, "Sending message to all peers except {:?} or the announced channel's counterparties: {:?}", except_node, msg);
+                               log_gossip!(self.logger, "Sending message to all peers except {:?} or the announced channel's counterparties: {:?}", except_node, msg);
                                let encoded_msg = encode_msg!(msg);
 
                                for (_, peer) in peers.peers.iter_mut() {
@@ -1147,7 +1190,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                        if peer.pending_outbound_buffer.len() > OUTBOUND_BUFFER_LIMIT_DROP_GOSSIP
                                                || peer.msgs_sent_since_pong > BUFFER_DRAIN_MSGS_PER_TICK * FORWARD_INIT_SYNC_BUFFER_LIMIT_RATIO
                                        {
-                                               log_trace!(self.logger, "Skipping broadcast message to {:?} as its outbound buffer is full", peer.their_node_id);
+                                               log_gossip!(self.logger, "Skipping broadcast message to {:?} as its outbound buffer is full", peer.their_node_id);
                                                continue;
                                        }
                                        if peer.their_node_id.as_ref() == Some(&msg.contents.node_id_1) ||
@@ -1161,7 +1204,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                }
                        },
                        wire::Message::NodeAnnouncement(ref msg) => {
-                               log_trace!(self.logger, "Sending message to all peers except {:?} or the announced node: {:?}", except_node, msg);
+                               log_gossip!(self.logger, "Sending message to all peers except {:?} or the announced node: {:?}", except_node, msg);
                                let encoded_msg = encode_msg!(msg);
 
                                for (_, peer) in peers.peers.iter_mut() {
@@ -1172,7 +1215,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                        if peer.pending_outbound_buffer.len() > OUTBOUND_BUFFER_LIMIT_DROP_GOSSIP
                                                || peer.msgs_sent_since_pong > BUFFER_DRAIN_MSGS_PER_TICK * FORWARD_INIT_SYNC_BUFFER_LIMIT_RATIO
                                        {
-                                               log_trace!(self.logger, "Skipping broadcast message to {:?} as its outbound buffer is full", peer.their_node_id);
+                                               log_gossip!(self.logger, "Skipping broadcast message to {:?} as its outbound buffer is full", peer.their_node_id);
                                                continue;
                                        }
                                        if peer.their_node_id.as_ref() == Some(&msg.contents.node_id) {
@@ -1185,7 +1228,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                }
                        },
                        wire::Message::ChannelUpdate(ref msg) => {
-                               log_trace!(self.logger, "Sending message to all peers except {:?}: {:?}", except_node, msg);
+                               log_gossip!(self.logger, "Sending message to all peers except {:?}: {:?}", except_node, msg);
                                let encoded_msg = encode_msg!(msg);
 
                                for (_, peer) in peers.peers.iter_mut() {
@@ -1196,7 +1239,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                        if peer.pending_outbound_buffer.len() > OUTBOUND_BUFFER_LIMIT_DROP_GOSSIP
                                                || peer.msgs_sent_since_pong > BUFFER_DRAIN_MSGS_PER_TICK * FORWARD_INIT_SYNC_BUFFER_LIMIT_RATIO
                                        {
-                                               log_trace!(self.logger, "Skipping broadcast message to {:?} as its outbound buffer is full", peer.their_node_id);
+                                               log_gossip!(self.logger, "Skipping broadcast message to {:?} as its outbound buffer is full", peer.their_node_id);
                                                continue;
                                        }
                                        if except_node.is_some() && peer.their_node_id.as_ref() == except_node {
@@ -1344,21 +1387,31 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                        },
                                        MessageSendEvent::BroadcastChannelAnnouncement { msg, update_msg } => {
                                                log_debug!(self.logger, "Handling BroadcastChannelAnnouncement event in peer_handler for short channel id {}", msg.contents.short_channel_id);
-                                               if self.message_handler.route_handler.handle_channel_announcement(&msg).is_ok() && self.message_handler.route_handler.handle_channel_update(&update_msg).is_ok() {
-                                                       self.forward_broadcast_msg(peers, &wire::Message::ChannelAnnouncement(msg), None);
-                                                       self.forward_broadcast_msg(peers, &wire::Message::ChannelUpdate(update_msg), None);
+                                               match self.message_handler.route_handler.handle_channel_announcement(&msg) {
+                                                       Ok(_) | Err(LightningError { action: msgs::ErrorAction::IgnoreDuplicateGossip, .. }) =>
+                                                               self.forward_broadcast_msg(peers, &wire::Message::ChannelAnnouncement(msg), None),
+                                                       _ => {},
+                                               }
+                                               match self.message_handler.route_handler.handle_channel_update(&update_msg) {
+                                                       Ok(_) | Err(LightningError { action: msgs::ErrorAction::IgnoreDuplicateGossip, .. }) =>
+                                                               self.forward_broadcast_msg(peers, &wire::Message::ChannelUpdate(update_msg), None),
+                                                       _ => {},
                                                }
                                        },
                                        MessageSendEvent::BroadcastNodeAnnouncement { msg } => {
                                                log_debug!(self.logger, "Handling BroadcastNodeAnnouncement event in peer_handler");
-                                               if self.message_handler.route_handler.handle_node_announcement(&msg).is_ok() {
-                                                       self.forward_broadcast_msg(peers, &wire::Message::NodeAnnouncement(msg), None);
+                                               match self.message_handler.route_handler.handle_node_announcement(&msg) {
+                                                       Ok(_) | Err(LightningError { action: msgs::ErrorAction::IgnoreDuplicateGossip, .. }) =>
+                                                               self.forward_broadcast_msg(peers, &wire::Message::NodeAnnouncement(msg), None),
+                                                       _ => {},
                                                }
                                        },
                                        MessageSendEvent::BroadcastChannelUpdate { msg } => {
                                                log_debug!(self.logger, "Handling BroadcastChannelUpdate event in peer_handler for short channel id {}", msg.contents.short_channel_id);
-                                               if self.message_handler.route_handler.handle_channel_update(&msg).is_ok() {
-                                                       self.forward_broadcast_msg(peers, &wire::Message::ChannelUpdate(msg), None);
+                                               match self.message_handler.route_handler.handle_channel_update(&msg) {
+                                                       Ok(_) | Err(LightningError { action: msgs::ErrorAction::IgnoreDuplicateGossip, .. }) =>
+                                                               self.forward_broadcast_msg(peers, &wire::Message::ChannelUpdate(msg), None),
+                                                       _ => {},
                                                }
                                        },
                                        MessageSendEvent::SendChannelUpdate { ref node_id, ref msg } => {
@@ -1381,7 +1434,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                                                                        // room in the send buffer, put the error message there...
                                                                                        self.do_attempt_write_data(&mut descriptor, &mut peer);
                                                                                } else {
-                                                                                       log_trace!(self.logger, "Handling DisconnectPeer HandleError event in peer_handler for node {} with no message", log_pubkey!(node_id));
+                                                                                       log_gossip!(self.logger, "Handling DisconnectPeer HandleError event in peer_handler for node {} with no message", log_pubkey!(node_id));
                                                                                }
                                                                        }
                                                                        descriptor.disconnect_socket();
@@ -1391,6 +1444,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                                        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::IgnoreDuplicateGossip => {},
                                                        msgs::ErrorAction::IgnoreError => {
                                                                log_debug!(self.logger, "Received a HandleError event to be ignored for node {}", log_pubkey!(node_id));
                                                        },
@@ -1400,6 +1454,12 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                                                                msg.data);
                                                                self.enqueue_message(get_peer_for_forwarding!(node_id), msg);
                                                        },
+                                                       msgs::ErrorAction::SendWarningMessage { ref msg, ref log_level } => {
+                                                               log_given_level!(self.logger, *log_level, "Handling SendWarningMessage HandleError event in peer_handler for node {} with message {}",
+                                                                               log_pubkey!(node_id),
+                                                                               msg.data);
+                                                               self.enqueue_message(get_peer_for_forwarding!(node_id), msg);
+                                                       },
                                                }
                                        },
                                        MessageSendEvent::SendChannelRangeQuery { ref node_id, ref msg } => {
@@ -1409,7 +1469,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                                self.enqueue_message(get_peer_for_forwarding!(node_id), msg);
                                        }
                                        MessageSendEvent::SendReplyChannelRange { ref node_id, ref msg } => {
-                                               log_trace!(self.logger, "Handling SendReplyChannelRange event in peer_handler for node {} with num_scids={} first_blocknum={} number_of_blocks={}, sync_complete={}",
+                                               log_gossip!(self.logger, "Handling SendReplyChannelRange event in peer_handler for node {} with num_scids={} first_blocknum={} number_of_blocks={}, sync_complete={}",
                                                        log_pubkey!(node_id),
                                                        msg.short_channel_ids.len(),
                                                        msg.first_blocknum,
@@ -1512,9 +1572,9 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
        /// Send pings to each peer and disconnect those which did not respond to the last round of
        /// pings.
        ///
-       /// This may be called on any timescale you want, however, roughly once every five to ten
-       /// seconds is preferred. The call rate determines both how often we send a ping to our peers
-       /// and how much time they have to respond before we disconnect them.
+       /// This may be called on any timescale you want, however, roughly once every ten seconds is
+       /// preferred. The call rate determines both how often we send a ping to our peers and how much
+       /// time they have to respond before we disconnect them.
        ///
        /// May call [`send_data`] on all [`SocketDescriptor`]s. Thus, be very careful with reentrancy
        /// issues!
@@ -1530,12 +1590,29 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                        let peer_count = peers.len();
 
                        peers.retain(|descriptor, peer| {
-                               if !peer.channel_encryptor.is_ready_for_encryption() {
-                                       // The peer needs to complete its handshake before we can exchange messages
+                               let mut do_disconnect_peer = false;
+                               if !peer.channel_encryptor.is_ready_for_encryption() || peer.their_node_id.is_none() {
+                                       // The peer needs to complete its handshake before we can exchange messages. We
+                                       // give peers one timer tick to complete handshake, reusing
+                                       // `awaiting_pong_timer_tick_intervals` to track number of timer ticks taken
+                                       // for handshake completion.
+                                       if peer.awaiting_pong_timer_tick_intervals != 0 {
+                                               do_disconnect_peer = true;
+                                       } else {
+                                               peer.awaiting_pong_timer_tick_intervals = 1;
+                                               return true;
+                                       }
+                               }
+
+                               if peer.awaiting_pong_timer_tick_intervals == -1 {
+                                       // Magic value set in `maybe_send_extra_ping`.
+                                       peer.awaiting_pong_timer_tick_intervals = 1;
+                                       peer.received_message_since_timer_tick = false;
                                        return true;
                                }
 
-                               if (peer.awaiting_pong_timer_tick_intervals > 0 && !peer.received_message_since_timer_tick)
+                               if do_disconnect_peer
+                                       || (peer.awaiting_pong_timer_tick_intervals > 0 && !peer.received_message_since_timer_tick)
                                        || peer.awaiting_pong_timer_tick_intervals as u64 >
                                                MAX_BUFFER_DRAIN_TICK_INTERVALS_PER_PEER as u64 * peer_count as u64
                                {
@@ -1546,21 +1623,11 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
                                                        node_id_to_descriptor.remove(&node_id);
                                                        self.message_handler.chan_handler.peer_disconnected(&node_id, false);
                                                }
-                                               None => {
-                                                       // This can't actually happen as we should have hit
-                                                       // is_ready_for_encryption() previously on this same peer.
-                                                       unreachable!();
-                                               },
+                                               None => {},
                                        }
                                        return false;
                                }
-
                                peer.received_message_since_timer_tick = false;
-                               if peer.awaiting_pong_timer_tick_intervals == -1 {
-                                       // Magic value set in `maybe_send_extra_ping`.
-                                       peer.awaiting_pong_timer_tick_intervals = 1;
-                                       return true;
-                               }
 
                                if peer.awaiting_pong_timer_tick_intervals > 0 {
                                        peer.awaiting_pong_timer_tick_intervals += 1;
@@ -1585,6 +1652,15 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
        }
 }
 
+fn is_gossip_msg(type_id: u16) -> bool {
+       match type_id {
+               msgs::ChannelAnnouncement::TYPE |
+               msgs::ChannelUpdate::TYPE |
+               msgs::NodeAnnouncement::TYPE => true,
+               _ => false
+       }
+}
+
 #[cfg(test)]
 mod tests {
        use ln::peer_handler::{PeerManager, MessageHandler, SocketDescriptor, IgnoringMessageHandler};
@@ -1758,4 +1834,37 @@ mod tests {
                assert_eq!(cfgs[1].routing_handler.chan_upds_recvd.load(Ordering::Acquire), 100);
                assert_eq!(cfgs[1].routing_handler.chan_anns_recvd.load(Ordering::Acquire), 50);
        }
+
+       #[test]
+       fn test_handshake_timeout() {
+               // Tests that we time out a peer still waiting on handshake completion after a full timer
+               // tick.
+               let cfgs = create_peermgr_cfgs(2);
+               cfgs[0].routing_handler.request_full_sync.store(true, Ordering::Release);
+               cfgs[1].routing_handler.request_full_sync.store(true, Ordering::Release);
+               let peers = create_network(2, &cfgs);
+
+               let secp_ctx = Secp256k1::new();
+               let a_id = PublicKey::from_secret_key(&secp_ctx, &peers[0].our_node_secret);
+               let mut fd_a = FileDescriptor { fd: 1, outbound_data: Arc::new(Mutex::new(Vec::new())) };
+               let mut fd_b = FileDescriptor { fd: 1, outbound_data: Arc::new(Mutex::new(Vec::new())) };
+               let initial_data = peers[1].new_outbound_connection(a_id, fd_b.clone()).unwrap();
+               peers[0].new_inbound_connection(fd_a.clone()).unwrap();
+
+               // If we get a single timer tick before completion, that's fine
+               assert_eq!(peers[0].peers.lock().unwrap().peers.len(), 1);
+               peers[0].timer_tick_occurred();
+               assert_eq!(peers[0].peers.lock().unwrap().peers.len(), 1);
+
+               assert_eq!(peers[0].read_event(&mut fd_a, &initial_data).unwrap(), false);
+               peers[0].process_events();
+               assert_eq!(peers[1].read_event(&mut fd_b, &fd_a.outbound_data.lock().unwrap().split_off(0)).unwrap(), false);
+               peers[1].process_events();
+
+               // ...but if we get a second timer tick, we should disconnect the peer
+               peers[0].timer_tick_occurred();
+               assert_eq!(peers[0].peers.lock().unwrap().peers.len(), 0);
+
+               assert!(peers[0].read_event(&mut fd_a, &fd_b.outbound_data.lock().unwrap().split_off(0)).is_err());
+       }
 }