discovery: add verbose network messages related logs

discovery/gossiper.go

@@ -757,6 +757,8 @@ func (d *deDupedAnnouncements) reset() {
 // and the set of senders is updated to reflect which node sent us this
 // message.
 func (d *deDupedAnnouncements) addMsg(message networkMsg) {
+	log.Tracef("Adding network message: %v to batch", message.msg.MsgType())
+
 	// Depending on the message type (channel announcement, channel update,
 	// or node announcement), the message is added to the corresponding map
 	// in deDupedAnnouncements. Because each identifying key can have at
@@ -806,6 +808,10 @@ func (d *deDupedAnnouncements) addMsg(message networkMsg) {
 		// If we already had this message with a strictly newer
 		// timestamp, then we'll just discard the message we got.
 		if oldTimestamp > msg.Timestamp {
+			log.Debugf("Ignored outdated network message: "+
+				"peer=%v, source=%x, msg=%s, ", message.peer,
+				message.source.SerializeCompressed(),
+				msg.MsgType())
 			return
 		}
 
@@ -1025,6 +1031,9 @@ func (d *AuthenticatedGossiper) networkHandler() {
 		// sub-systems below us, then craft, sign, and broadcast a new
 		// ChannelUpdate for the set of affected clients.
 		case policyUpdate := <-d.chanPolicyUpdates:
+			log.Tracef("Received channel %d policy update requests",
+				len(policyUpdate.edgesToUpdate))
+
 			// First, we'll now create new fully signed updates for
 			// the affected channels and also update the underlying
 			// graph with the new state.
@@ -1044,6 +1053,13 @@ func (d *AuthenticatedGossiper) networkHandler() {
 			announcements.AddMsgs(newChanUpdates...)
 
 		case announcement := <-d.networkMsgs:
+			log.Tracef("Received network message: "+
+				"peer=%v, source=%x, msg=%s, is_remote=%v",
+				announcement.peer,
+				announcement.source.SerializeCompressed(),
+				announcement.msg.MsgType(),
+				announcement.isRemote)
+
 			// We should only broadcast this message forward if it
 			// originated from us or it wasn't received as part of
 			// our initial historical sync.
@@ -1057,6 +1073,11 @@ func (d *AuthenticatedGossiper) networkHandler() {
 				emittedAnnouncements, _ := d.processNetworkAnnouncement(
 					announcement,
 				)
+				log.Debugf("Processed network message %s, "+
+					"returned len(announcements)=%v",
+					announcement.msg.MsgType(),
+					len(emittedAnnouncements))
+
 				if emittedAnnouncements != nil {
 					announcements.AddMsgs(
 						emittedAnnouncements...,
@@ -1111,6 +1132,13 @@ func (d *AuthenticatedGossiper) networkHandler() {
 					announcement,
 				)
 
+				log.Tracef("Processed network message %s, "+
+					"returned len(announcements)=%v, "+
+					"allowDependents=%v",
+					announcement.msg.MsgType(),
+					len(emittedAnnouncements),
+					allowDependents)
+
 				// If this message had any dependencies, then
 				// we can now signal them to continue.
 				validationBarrier.SignalDependants(
@@ -1589,6 +1617,10 @@ func (d *AuthenticatedGossiper) addNode(msg *lnwire.NodeAnnouncement,
 func (d *AuthenticatedGossiper) processNetworkAnnouncement(
 	nMsg *networkMsg) ([]networkMsg, bool) {
 
+	log.Debugf("Processing network message: peer=%v, source=%x, msg=%s, "+
+		"is_remote=%v", nMsg.peer, nMsg.source.SerializeCompressed(),
+		nMsg.msg.MsgType(), nMsg.isRemote)
+
 	isPremature := func(chanID lnwire.ShortChannelID, delta uint32) bool {
 		// TODO(roasbeef) make height delta 6
 		//  * or configurable
@@ -1616,17 +1648,25 @@ func (d *AuthenticatedGossiper) processNetworkAnnouncement(
 		// newer update for this node so we can skip validating
 		// signatures if not required.
 		if d.cfg.Router.IsStaleNode(msg.NodeID, timestamp) {
+			log.Debugf("Skipped processing stale node: %x",
+				msg.NodeID)
 			nMsg.err <- nil
 			return nil, true
 		}
 
 		if err := d.addNode(msg, schedulerOp...); err != nil {
-			if routing.IsError(err, routing.ErrOutdated,
+			log.Debugf("Adding node: %x got error: %v",
-				routing.ErrIgnored) {
+				msg.NodeID, err)
 
-				log.Debug(err)
+			switch {
-			} else if err != routing.ErrVBarrierShuttingDown {
+			case routing.IsError(err, routing.ErrOutdated,
+				routing.ErrIgnored):
+
+			case err == routing.ErrVBarrierShuttingDown:
+
+			default:
 				log.Error(err)
+
 			}
 
 			nMsg.err <- err
@@ -1817,7 +1857,7 @@ func (d *AuthenticatedGossiper) processNetworkAnnouncement(
 				log.Debugf("Router rejected channel "+
 					"edge: %v", err)
 			} else {
-				log.Tracef("Router rejected channel "+
+				log.Debugf("Router rejected channel "+
 					"edge: %v", err)
 
 				key := newRejectCacheKey(
@@ -1943,6 +1983,12 @@ func (d *AuthenticatedGossiper) processNetworkAnnouncement(
 		if d.cfg.Router.IsStaleEdgePolicy(
 			msg.ShortChannelID, timestamp, msg.ChannelFlags,
 		) {
+
+			log.Debugf("Ignored stale edge policy: peer=%v, "+
+				"source=%x, msg=%s, is_remote=%v", nMsg.peer,
+				nMsg.source.SerializeCompressed(),
+				nMsg.msg.MsgType(), nMsg.isRemote)
+
 			nMsg.err <- nil
 			return nil, true
 		}
@@ -2166,6 +2212,10 @@ func (d *AuthenticatedGossiper) processNetworkAnnouncement(
 				chanInfo, msg.ChannelFlags,
 			)
 
+			log.Debugf("The message %v has no AuthProof, sending "+
+				"the update to remote peer %x",
+				msg.MsgType(), remotePubKey)
+
 			// Now, we'll attempt to send the channel update message
 			// reliably to the remote peer in the background, so
 			// that we don't block if the peer happens to be offline

discovery/sync_manager.go

@@ -492,6 +492,10 @@ func (m *SyncManager) createGossipSyncer(peer lnpeer.Peer) *GossipSyncer {
 	// handle any sync transitions.
 	s.setSyncState(chansSynced)
 	s.setSyncType(PassiveSync)
+
+	log.Debugf("Created new GossipSyncer[state=%s type=%s] for peer=%v",
+		s.syncState(), s.SyncType(), peer)
+
 	return s
 }