From 2b8e9a0d36071dfa04f67786affcca5995b4c04a Mon Sep 17 00:00:00 2001
From: yyforyongyu <yy2452@columbia.edu>
Date: Mon, 20 Mar 2023 16:35:09 +0800
Subject: [PATCH] multi: add more trace logs regarding link activate flow

---
 discovery/gossiper.go      | 2 +-
 discovery/message_store.go | 9 ++++++++-
 htlcswitch/link.go         | 3 +++
 peer/brontide.go           | 6 +++++-
 4 files changed, 17 insertions(+), 3 deletions(-)

diff --git a/discovery/gossiper.go b/discovery/gossiper.go
index c02cd0b10..5251c06b2 100644
--- a/discovery/gossiper.go
+++ b/discovery/gossiper.go
@@ -1294,7 +1294,7 @@ func (d *AuthenticatedGossiper) sendRemoteBatch(annBatch []msgWithSenders) {
 	// We'll first attempt to filter out this new message for all peers
 	// that have active gossip syncers active.
 	for pub, syncer := range syncerPeers {
-		log.Tracef("Sending messages batch to GossipSyncer(%x)", pub)
+		log.Tracef("Sending messages batch to GossipSyncer(%s)", pub)
 		syncer.FilterGossipMsgs(annBatch...)
 	}
 
diff --git a/discovery/message_store.go b/discovery/message_store.go
index 40f2df78a..cf228eee7 100644
--- a/discovery/message_store.go
+++ b/discovery/message_store.go
@@ -111,7 +111,11 @@ func messageStoreKey(msg lnwire.Message, peerPubKey [33]byte) ([]byte, error) {
 
 // AddMessage adds a message to the store for this peer.
 func (s *MessageStore) AddMessage(msg lnwire.Message, peerPubKey [33]byte) error {
-	// Construct the key for which we'll find this message with in the store.
+	log.Tracef("Adding message of type %v to store for peer %x",
+		msg.MsgType(), peerPubKey)
+
+	// Construct the key for which we'll find this message with in the
+	// store.
 	msgKey, err := messageStoreKey(msg, peerPubKey)
 	if err != nil {
 		return err
@@ -137,6 +141,9 @@ func (s *MessageStore) AddMessage(msg lnwire.Message, peerPubKey [33]byte) error
 func (s *MessageStore) DeleteMessage(msg lnwire.Message,
 	peerPubKey [33]byte) error {
 
+	log.Tracef("Deleting message of type %v from store for peer %x",
+		msg.MsgType(), peerPubKey)
+
 	// Construct the key for which we'll find this message with in the
 	// store.
 	msgKey, err := messageStoreKey(msg, peerPubKey)
diff --git a/htlcswitch/link.go b/htlcswitch/link.go
index b1836c7c7..335ec351f 100644
--- a/htlcswitch/link.go
+++ b/htlcswitch/link.go
@@ -710,6 +710,9 @@ func (l *channelLink) syncChanStates() error {
 	// first message sent MUST be the ChanSync message.
 	select {
 	case msg := <-l.upstream:
+		l.log.Tracef("Received msg=%v from peer(%x)", msg.MsgType(),
+			l.cfg.Peer.PubKey())
+
 		remoteChanSyncMsg, ok := msg.(*lnwire.ChannelReestablish)
 		if !ok {
 			return fmt.Errorf("first message sent to sync "+
diff --git a/peer/brontide.go b/peer/brontide.go
index 9ea85edd1..09f016851 100644
--- a/peer/brontide.go
+++ b/peer/brontide.go
@@ -776,7 +776,8 @@ func (p *Brontide) loadActiveChannels(chans []*channeldb.OpenChannel) (
 
 		chanID := lnwire.NewChanIDFromOutPoint(chanPoint)
 
-		p.log.Infof("loading ChannelPoint(%v)", chanPoint)
+		p.log.Infof("Loading ChannelPoint(%v), isPending=%v",
+			chanPoint, lnChan.IsPending())
 
 		// Skip adding any permanently irreconcilable channels to the
 		// htlcswitch.
@@ -1318,6 +1319,8 @@ func (ms *msgStream) AddMsg(msg lnwire.Message) {
 func waitUntilLinkActive(p *Brontide,
 	cid lnwire.ChannelID) htlcswitch.ChannelUpdateHandler {
 
+	p.log.Tracef("Waiting for link=%v to be active", cid)
+
 	// Subscribe to receive channel events.
 	//
 	// NOTE: If the link is already active by SubscribeChannelEvents, then
@@ -1395,6 +1398,7 @@ func newChanMsgStream(p *Brontide, cid lnwire.ChannelID) *msgStream {
 			// If the link is still not active and the calling function
 			// errored out, just return.
 			if chanLink == nil {
+				p.log.Warnf("Link=%v is not active")
 				return
 			}
 		}