From 9a75400295ac23d1e6ffb57bdbaf74db7725b6f4 Mon Sep 17 00:00:00 2001 From: ziggie Date: Sun, 6 Jul 2025 09:28:53 +0200 Subject: [PATCH 1/2] multi: add logs to debug potential payment sending issue --- htlcswitch/switch.go | 3 +++ routing/bandwidth.go | 5 ++++- routing/pathfind.go | 20 ++++++++++++++++++++ routing/unified_edges.go | 3 ++- 4 files changed, 29 insertions(+), 2 deletions(-) diff --git a/htlcswitch/switch.go b/htlcswitch/switch.go index 38b308b69..0d85805b9 100644 --- a/htlcswitch/switch.go +++ b/htlcswitch/switch.go @@ -2229,6 +2229,9 @@ func (s *Switch) GetLinkByShortID(chanID lnwire.ShortChannelID) (ChannelLink, func (s *Switch) getLinkByShortID(chanID lnwire.ShortChannelID) (ChannelLink, error) { link, ok := s.forwardingIndex[chanID] if !ok { + log.Debugf("Link not found in forwarding index using "+ + "chanID=%v", chanID) + return nil, ErrChannelLinkNotFound } diff --git a/routing/bandwidth.go b/routing/bandwidth.go index e9cfb5968..31466e78b 100644 --- a/routing/bandwidth.go +++ b/routing/bandwidth.go @@ -91,7 +91,10 @@ func (b *bandwidthManager) getBandwidth(cid lnwire.ShortChannelID, if err != nil { // If the link isn't online, then we'll report that it has // zero bandwidth. - log.Warnf("ShortChannelID=%v: link not found: %v", cid, err) + log.Warnf("ShortChannelID=%v: link not found when "+ + "determining bandwidth for local channel=%v, "+ + "reporting 0 bandwidth", cid, err) + return 0 } diff --git a/routing/pathfind.go b/routing/pathfind.go index f489173f9..91bec3861 100644 --- a/routing/pathfind.go +++ b/routing/pathfind.go @@ -514,7 +514,18 @@ func getOutgoingBalance(node route.Vertex, outgoingChans map[uint64]struct{}, var max, total lnwire.MilliSatoshi cb := func(channel *graphdb.DirectedChannel) error { + shortID := lnwire.NewShortChanIDFromInt(channel.ChannelID) + + // This log line is needed to debug issues in case we do not + // have a channel in our graph for some reason when evaluating + // the local balance. Otherwise we could not tell whether all + // channels are being evaluated. + log.Tracef("Evaluating channel %v for local balance", shortID) + if !channel.OutPolicySet { + log.Debugf("ShortChannelID=%v: has no out policy set, "+ + "skipping", shortID) + return nil } @@ -536,6 +547,12 @@ func getOutgoingBalance(node route.Vertex, outgoingChans map[uint64]struct{}, // we've already queried the bandwidth hints. if !ok { bandwidth = lnwire.NewMSatFromSatoshis(channel.Capacity) + + log.Warnf("ShortChannelID=%v: not found in the local "+ + "channels map of the bandwidth manager, "+ + "using channel capacity=%v as bandwidth for "+ + "this channel", shortID, bandwidth, + ) } if bandwidth > max { @@ -545,6 +562,9 @@ func getOutgoingBalance(node route.Vertex, outgoingChans map[uint64]struct{}, var overflow bool total, overflow = overflowSafeAdd(total, bandwidth) if overflow { + log.Warnf("ShortChannelID=%v: overflow detected, "+ + "setting total to max value", shortID) + // If the current total and the bandwidth would // overflow the maximum value, we set the total to the // maximum value. Which is more milli-satoshis than are diff --git a/routing/unified_edges.go b/routing/unified_edges.go index 9e28a53c0..bf2f75dbf 100644 --- a/routing/unified_edges.go +++ b/routing/unified_edges.go @@ -280,8 +280,9 @@ func (u *edgeUnifier) getEdgeLocal(netAmtReceived lnwire.MilliSatoshi, edge.policy.ChannelID, amt, ) if !ok { - log.Debugf("Cannot get bandwidth for edge %v, use max "+ + log.Warnf("Cannot get bandwidth for edge %v, use max "+ "instead", edge.policy.ChannelID) + bandwidth = lnwire.MaxMilliSatoshi } From eb4c87cdcbcfbe3dfc0f12aaabcf5d55660c704a Mon Sep 17 00:00:00 2001 From: ziggie Date: Mon, 7 Jul 2025 19:11:59 +0200 Subject: [PATCH 2/2] routing: return error for getBandwidth and log it --- routing/bandwidth.go | 36 +++++++++++++++++------------------- routing/pathfind.go | 3 +-- 2 files changed, 18 insertions(+), 21 deletions(-) diff --git a/routing/bandwidth.go b/routing/bandwidth.go index 31466e78b..f806b03d3 100644 --- a/routing/bandwidth.go +++ b/routing/bandwidth.go @@ -85,25 +85,18 @@ func newBandwidthManager(graph Graph, sourceNode route.Vertex, // queried is one of our local channels, so any failure to retrieve the link // is interpreted as the link being offline. func (b *bandwidthManager) getBandwidth(cid lnwire.ShortChannelID, - amount lnwire.MilliSatoshi) lnwire.MilliSatoshi { + amount lnwire.MilliSatoshi) (lnwire.MilliSatoshi, error) { link, err := b.getLink(cid) if err != nil { - // If the link isn't online, then we'll report that it has - // zero bandwidth. - log.Warnf("ShortChannelID=%v: link not found when "+ - "determining bandwidth for local channel=%v, "+ - "reporting 0 bandwidth", cid, err) - - return 0 + return 0, fmt.Errorf("error querying switch for link: %w", err) } // If the link is found within the switch, but it isn't yet eligible // to forward any HTLCs, then we'll treat it as if it isn't online in // the first place. if !link.EligibleToForward() { - log.Warnf("ShortChannelID=%v: not eligible to forward", cid) - return 0 + return 0, fmt.Errorf("link not eligible to forward") } // bandwidthResult is an inline type that we'll use to pass the @@ -168,10 +161,8 @@ func (b *bandwidthManager) getBandwidth(cid lnwire.ShortChannelID, }, ).Unpack() if err != nil { - log.Errorf("ShortChannelID=%v: failed to get bandwidth from "+ - "external traffic shaper: %v", cid, err) - - return 0 + return 0, fmt.Errorf("failed to consult external traffic "+ + "shaper: %w", err) } htlcAmount := result.htlcAmount.UnwrapOr(amount) @@ -179,9 +170,8 @@ func (b *bandwidthManager) getBandwidth(cid lnwire.ShortChannelID, // If our link isn't currently in a state where it can add another // outgoing htlc, treat the link as unusable. if err := link.MayAddOutgoingHtlc(htlcAmount); err != nil { - log.Warnf("ShortChannelID=%v: cannot add outgoing "+ - "htlc with amount %v: %v", cid, htlcAmount, err) - return 0 + return 0, fmt.Errorf("cannot add outgoing htlc to channel %v "+ + "with amount %v: %w", cid, htlcAmount, err) } // If the external traffic shaper determined the bandwidth, we'll return @@ -189,7 +179,7 @@ func (b *bandwidthManager) getBandwidth(cid lnwire.ShortChannelID, // available on that channel). reportedBandwidth := result.bandwidth.UnwrapOr(linkBandwidth) - return reportedBandwidth + return reportedBandwidth, nil } // availableChanBandwidth returns the total available bandwidth for a channel @@ -204,7 +194,15 @@ func (b *bandwidthManager) availableChanBandwidth(channelID uint64, return 0, false } - return b.getBandwidth(shortID, amount), true + bandwidth, err := b.getBandwidth(shortID, amount) + if err != nil { + log.Warnf("failed to get bandwidth for channel %v: %v", + shortID, err) + + return 0, true + } + + return bandwidth, true } // firstHopCustomBlob returns the custom blob for the first hop of the payment, diff --git a/routing/pathfind.go b/routing/pathfind.go index 91bec3861..b22e7fd1c 100644 --- a/routing/pathfind.go +++ b/routing/pathfind.go @@ -551,8 +551,7 @@ func getOutgoingBalance(node route.Vertex, outgoingChans map[uint64]struct{}, log.Warnf("ShortChannelID=%v: not found in the local "+ "channels map of the bandwidth manager, "+ "using channel capacity=%v as bandwidth for "+ - "this channel", shortID, bandwidth, - ) + "this channel", shortID, bandwidth) } if bandwidth > max {