From 4d05730c791d4cf0f38dc9e2469e29ec5c671274 Mon Sep 17 00:00:00 2001 From: yyforyongyu Date: Sat, 8 Mar 2025 21:57:00 +0800 Subject: [PATCH 1/5] tor: fix msg order in `TestReconnectSucceed` --- tor/controller_test.go | 37 +++++++++++++++++++------------------ 1 file changed, 19 insertions(+), 18 deletions(-) diff --git a/tor/controller_test.go b/tor/controller_test.go index e109f49b7..279b4f39e 100644 --- a/tor/controller_test.go +++ b/tor/controller_test.go @@ -319,14 +319,20 @@ func TestReconnectSucceed(t *testing.T) { // Close the old conn before reconnection. require.NoError(t, proxy.serverConn.Close()) - // Accept the connection inside a goroutine. We will also write some - // data so that the reconnection can succeed. We will mock three writes - // and two reads inside our proxy server, - // - write protocol info - // - read auth info - // - write auth challenge - // - read auth challenge - // - write OK + // Accept the connection inside a goroutine. When the client makes a + // reconnection, the messages flow is, + // 1. the client sends the command PROTOCOLINFO to the server. + // 2. the server responds with its protocol version. + // 3. the client reads the response and sends the command AUTHENTICATE + // to the server + // 4. the server responds with the authentication info. + // + // From the server's PoV, We need to mock two reads and two writes + // inside the connection, + // 1. read the command PROTOCOLINFO sent from the client. + // 2. write protocol info so the client can read it. + // 3. read the command AUTHENTICATE sent from the client. + // 4. write auth challenge so the client can read it. go func() { // Accept the new connection. server, err := proxy.server.Accept() @@ -335,6 +341,11 @@ func TestReconnectSucceed(t *testing.T) { t.Logf("server listening on %v, client listening on %v", server.LocalAddr(), server.RemoteAddr()) + // Read the protocol command from the client. + buf := make([]byte, 65535) + _, err = server.Read(buf) + require.NoError(t, err) + // Write the protocol info. resp := "250-PROTOCOLINFO 1\n" + "250-AUTH METHODS=NULL\n" + @@ -343,7 +354,6 @@ func TestReconnectSucceed(t *testing.T) { require.NoErrorf(t, err, "failed to write protocol info") // Read the auth info from the client. - buf := make([]byte, 65535) _, err = server.Read(buf) require.NoError(t, err) @@ -351,15 +361,6 @@ func TestReconnectSucceed(t *testing.T) { resp = "250 AUTHCHALLENGE SERVERHASH=fake\n" _, err = server.Write([]byte(resp)) require.NoErrorf(t, err, "failed to write auth challenge") - - // Read the auth challenge resp from the client. - _, err = server.Read(buf) - require.NoError(t, err) - - // Write OK resp. - resp = "250 OK\n" - _, err = server.Write([]byte(resp)) - require.NoErrorf(t, err, "failed to write response auth") }() // Reconnect should succeed. From 37799b95b745a1fd99f8a0515347ca0bb9665264 Mon Sep 17 00:00:00 2001 From: yyforyongyu Date: Mon, 10 Mar 2025 14:28:12 +0800 Subject: [PATCH 2/5] discovery: fix state transition in `GossipSyncer` Previously, we would set the state of the syncer after sending the msg, which has the following flow, 1. In state `queryNewChannels`, we send the msg `QueryShortChanIDs`. 2. Once the msg is sent, we change to state `waitingQueryChanReply`. But there's no guarantee the remote won't reply back inbetween the two step. When that happens, our syncer would still be in state `queryNewChannels`, causing the following error, ``` [ERR] DISC gossiper.go:873: Process query msg from peer [Alice] got unexpected msg *lnwire.ReplyShortChanIDsEnd received in state queryNewChannels ``` To fix it, we now make sure the state is updated before sending the msg. --- discovery/syncer.go | 19 +++++++++++-------- discovery/syncer_test.go | 8 ++------ 2 files changed, 13 insertions(+), 14 deletions(-) diff --git a/discovery/syncer.go b/discovery/syncer.go index f0ce4ffcb..6b19908d5 100644 --- a/discovery/syncer.go +++ b/discovery/syncer.go @@ -571,15 +571,11 @@ func (g *GossipSyncer) channelGraphSyncer() { // First, we'll attempt to continue our channel // synchronization by continuing to send off another // query chunk. - done, err := g.synchronizeChanIDs() - if err != nil { - log.Errorf("Unable to sync chan IDs: %v", err) - } + done := g.synchronizeChanIDs() // If this wasn't our last query, then we'll need to // transition to our waiting state. if !done { - g.setSyncState(waitingQueryChanReply) continue } @@ -736,14 +732,15 @@ func (g *GossipSyncer) sendGossipTimestampRange(firstTimestamp time.Time, // been queried for with a response received. We'll chunk our requests as // required to ensure they fit into a single message. We may re-renter this // state in the case that chunking is required. -func (g *GossipSyncer) synchronizeChanIDs() (bool, error) { +func (g *GossipSyncer) synchronizeChanIDs() bool { // If we're in this state yet there are no more new channels to query // for, then we'll transition to our final synced state and return true // to signal that we're fully synchronized. if len(g.newChansToQuery) == 0 { log.Infof("GossipSyncer(%x): no more chans to query", g.cfg.peerPub[:]) - return true, nil + + return true } // Otherwise, we'll issue our next chunked query to receive replies @@ -767,6 +764,9 @@ func (g *GossipSyncer) synchronizeChanIDs() (bool, error) { log.Infof("GossipSyncer(%x): querying for %v new channels", g.cfg.peerPub[:], len(queryChunk)) + // Change the state before sending the query msg. + g.setSyncState(waitingQueryChanReply) + // With our chunk obtained, we'll send over our next query, then return // false indicating that we're net yet fully synced. err := g.cfg.sendToPeer(&lnwire.QueryShortChanIDs{ @@ -774,8 +774,11 @@ func (g *GossipSyncer) synchronizeChanIDs() (bool, error) { EncodingType: lnwire.EncodingSortedPlain, ShortChanIDs: queryChunk, }) + if err != nil { + log.Errorf("Unable to sync chan IDs: %v", err) + } - return false, err + return false } // isLegacyReplyChannelRange determines where a ReplyChannelRange message is diff --git a/discovery/syncer_test.go b/discovery/syncer_test.go index ebc557525..47032e1ba 100644 --- a/discovery/syncer_test.go +++ b/discovery/syncer_test.go @@ -1478,10 +1478,7 @@ func TestGossipSyncerSynchronizeChanIDs(t *testing.T) { for i := 0; i < chunkSize*2; i += 2 { // With our set up complete, we'll request a sync of chan ID's. - done, err := syncer.synchronizeChanIDs() - if err != nil { - t.Fatalf("unable to sync chan IDs: %v", err) - } + done := syncer.synchronizeChanIDs() // At this point, we shouldn't yet be done as only 2 items // should have been queried for. @@ -1528,8 +1525,7 @@ func TestGossipSyncerSynchronizeChanIDs(t *testing.T) { } // If we issue another query, the syncer should tell us that it's done. - done, err := syncer.synchronizeChanIDs() - require.NoError(t, err, "unable to sync chan IDs") + done := syncer.synchronizeChanIDs() if done { t.Fatalf("syncer should be finished!") } From 51daa13cd7f268b2755aea4466d8ee64a32e2059 Mon Sep 17 00:00:00 2001 From: yyforyongyu Date: Sat, 8 Mar 2025 21:57:47 +0800 Subject: [PATCH 3/5] routerrpc: improve logging in `forwardInterceptor` --- lnrpc/routerrpc/forward_interceptor.go | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/lnrpc/routerrpc/forward_interceptor.go b/lnrpc/routerrpc/forward_interceptor.go index 72df3d019..6d6b3cf18 100644 --- a/lnrpc/routerrpc/forward_interceptor.go +++ b/lnrpc/routerrpc/forward_interceptor.go @@ -8,6 +8,7 @@ import ( "github.com/lightningnetwork/lnd/htlcswitch" "github.com/lightningnetwork/lnd/lnrpc" "github.com/lightningnetwork/lnd/lntypes" + "github.com/lightningnetwork/lnd/lnutils" "github.com/lightningnetwork/lnd/lnwire" "google.golang.org/grpc/codes" "google.golang.org/grpc/status" @@ -60,6 +61,9 @@ func (r *forwardInterceptor) run() error { return err } + log.Tracef("Received packet from stream: %v", + lnutils.SpewLogClosure(resp)) + if err := r.resolveFromClient(resp); err != nil { return err } @@ -73,7 +77,8 @@ func (r *forwardInterceptor) run() error { func (r *forwardInterceptor) onIntercept( htlc htlcswitch.InterceptedPacket) error { - log.Tracef("Sending intercepted packet to client %v", htlc) + log.Tracef("Sending intercepted packet to client %v", + lnutils.SpewLogClosure(htlc)) inKey := htlc.IncomingCircuit From d0abfbbaff8bb352769557066b288206ee55b7c3 Mon Sep 17 00:00:00 2001 From: yyforyongyu Date: Mon, 10 Mar 2025 14:06:10 +0800 Subject: [PATCH 4/5] itest: remove redundant resume action Removed a redundant resume action found in `testForwardInterceptorRestart`, which was put there likely due to a mistake. --- itest/lnd_forward_interceptor_test.go | 6 ------ 1 file changed, 6 deletions(-) diff --git a/itest/lnd_forward_interceptor_test.go b/itest/lnd_forward_interceptor_test.go index 7b25ffe12..e8c1f418a 100644 --- a/itest/lnd_forward_interceptor_test.go +++ b/itest/lnd_forward_interceptor_test.go @@ -438,12 +438,6 @@ func testForwardInterceptorRestart(ht *lntest.HarnessTest) { require.Equal(ht, lntest.CustomRecordsWithUnendorsed(customRecords), packet.InWireCustomRecords) - err = carolInterceptor.Send(&routerrpc.ForwardHtlcInterceptResponse{ - IncomingCircuitKey: packet.IncomingCircuitKey, - Action: actionResume, - }) - require.NoError(ht, err, "failed to send request") - // And now we forward the payment at Carol, expecting only an // endorsement signal in our incoming custom records. packet = ht.ReceiveHtlcInterceptor(carolInterceptor) From faf8ce161a4119e8a8d67e369fa7715812946321 Mon Sep 17 00:00:00 2001 From: yyforyongyu Date: Mon, 10 Mar 2025 17:03:00 +0800 Subject: [PATCH 5/5] docs: update release notes --- docs/release-notes/release-notes-0.19.0.md | 3 +++ 1 file changed, 3 insertions(+) diff --git a/docs/release-notes/release-notes-0.19.0.md b/docs/release-notes/release-notes-0.19.0.md index 0250dd68b..f0a400708 100644 --- a/docs/release-notes/release-notes-0.19.0.md +++ b/docs/release-notes/release-notes-0.19.0.md @@ -82,6 +82,9 @@ could lead to our ChannelUpdate rate limiting logic being prematurely triggered. +* [Fixed a bug](https://github.com/lightningnetwork/lnd/pull/9595) where the + initial graph sync query may be failed due to inconsistent state. + # New Features * [Support](https://github.com/lightningnetwork/lnd/pull/8390) for