From 85f4b13632f7579149f83593cf1ccc73da4c13f7 Mon Sep 17 00:00:00 2001 From: yyforyongyu Date: Wed, 22 Nov 2023 23:12:49 +0800 Subject: [PATCH] multi: enhance logging around channel reestablishment --- channeldb/channel.go | 36 ++++++++++++++++++++++++++++++++++++ htlcswitch/link.go | 5 +++-- peer/brontide.go | 3 ++- 3 files changed, 41 insertions(+), 3 deletions(-) diff --git a/channeldb/channel.go b/channeldb/channel.go index 67a32379e..dbd796c87 100644 --- a/channeldb/channel.go +++ b/channeldb/channel.go @@ -849,6 +849,30 @@ type OpenChannel struct { sync.RWMutex } +// String returns a string representation of the channel. +func (c *OpenChannel) String() string { + indexStr := "height=%v, local_htlc_index=%v, local_log_index=%v, " + + "remote_htlc_index=%v, remote_log_index=%v" + + commit := c.LocalCommitment + local := fmt.Sprintf(indexStr, commit.CommitHeight, + commit.LocalHtlcIndex, commit.LocalLogIndex, + commit.RemoteHtlcIndex, commit.RemoteLogIndex, + ) + + commit = c.RemoteCommitment + remote := fmt.Sprintf(indexStr, commit.CommitHeight, + commit.LocalHtlcIndex, commit.LocalLogIndex, + commit.RemoteHtlcIndex, commit.RemoteLogIndex, + ) + + return fmt.Sprintf("SCID=%v, status=%v, initiator=%v, pending=%v, "+ + "local commitment has %s, remote commitment has %s", + c.ShortChannelID, c.chanStatus, c.IsInitiator, c.IsPending, + local, remote, + ) +} + // ShortChanID returns the current ShortChannelID of this channel. func (c *OpenChannel) ShortChanID() lnwire.ShortChannelID { c.RLock() @@ -2100,6 +2124,10 @@ func (c *OpenChannel) ActiveHtlcs() []HTLC { // which ones are present on their commitment. remoteHtlcs := make(map[[32]byte]struct{}) for _, htlc := range c.RemoteCommitment.Htlcs { + log.Tracef("RemoteCommitment has htlc: id=%v, update=%v "+ + "incoming=%v", htlc.HtlcIndex, htlc.LogIndex, + htlc.Incoming) + onionHash := sha256.Sum256(htlc.OnionBlob[:]) remoteHtlcs[onionHash] = struct{}{} } @@ -2108,8 +2136,16 @@ func (c *OpenChannel) ActiveHtlcs() []HTLC { // as active if *we* know them as well. activeHtlcs := make([]HTLC, 0, len(remoteHtlcs)) for _, htlc := range c.LocalCommitment.Htlcs { + log.Tracef("LocalCommitment has htlc: id=%v, update=%v "+ + "incoming=%v", htlc.HtlcIndex, htlc.LogIndex, + htlc.Incoming) + onionHash := sha256.Sum256(htlc.OnionBlob[:]) if _, ok := remoteHtlcs[onionHash]; !ok { + log.Tracef("Skipped htlc due to onion mismatched: "+ + "id=%v, update=%v incoming=%v", + htlc.HtlcIndex, htlc.LogIndex, htlc.Incoming) + continue } diff --git a/htlcswitch/link.go b/htlcswitch/link.go index 2a1e49923..e302cf3d8 100644 --- a/htlcswitch/link.go +++ b/htlcswitch/link.go @@ -649,12 +649,13 @@ func (l *channelLink) createFailureWithUpdate(incoming bool, // flow. We'll compare out commitment chains with the remote party, and re-send // either a danging commit signature, a revocation, or both. func (l *channelLink) syncChanStates() error { - l.log.Info("attempting to re-synchronize") + chanState := l.channel.State() + + l.log.Infof("Attempting to re-synchronize channel: %v", chanState) // First, we'll generate our ChanSync message to send to the other // side. Based on this message, the remote party will decide if they // need to retransmit any data or not. - chanState := l.channel.State() localChanSyncMsg, err := chanState.ChanSyncMsg() if err != nil { return fmt.Errorf("unable to generate chan sync message for "+ diff --git a/peer/brontide.go b/peer/brontide.go index d7d93f4fa..35cdbd847 100644 --- a/peer/brontide.go +++ b/peer/brontide.go @@ -2009,7 +2009,8 @@ func messageSummary(msg lnwire.Message) string { msg.ChanID, int64(msg.FeePerKw)) case *lnwire.ChannelReestablish: - return fmt.Sprintf("next_local_height=%v, remote_tail_height=%v", + return fmt.Sprintf("chan_id=%v, next_local_height=%v, "+ + "remote_tail_height=%v", msg.ChanID, msg.NextLocalCommitHeight, msg.RemoteCommitTailHeight) case *lnwire.ReplyShortChanIDsEnd: