Merge pull request #1353 from bitromortac/2607-itest-flake

terminal: gate wallet-ready status on lnd's actual RPC readiness

docs/release-notes/release-notes-0.17.0.md

@@ -33,6 +33,13 @@
   expiration date would overwrite it to 0 (never expires). It now correctly
   defaults to -1 (no change).
 
+* [Gate wallet-ready status on lnd's actual RPC
+  readiness](https://github.com/lightninglabs/lightning-terminal/pull/1353):
+  Fixed a startup race where litd could report the LND sub-server as "Wallet
+  Ready" before lnd's RPC interceptor had actually left its
+  `WAITING_TO_START` state, so the very next call could still fail with
+  `rpc error: ... waiting to start`.
+
 ### Functional Changes/Additions
 
 * [Support for SQL database

itest/litd_node.go

@@ -899,31 +899,56 @@ func (hn *HarnessNode) WaitUntilStarted(conn grpc.ClientConnInterface,
 			return err
 		}
 
+		// LiT itself only reports Running once it has finished baking
+		// and writing its default macaroons to disk, so waiting for
+		// this closes the race between that and callers that read
+		// LitMacPath straight off disk right after we return.
+		litStatus, ok := states.SubServers[subservers.LIT]
+		if !ok || !litStatus.Running {
+			return fmt.Errorf("LiT has not yet started")
+		}
+
 		if faradayMode != terminal.ModeDisable {
 			faraday, ok := states.SubServers[subservers.FARADAY]
-			if !ok || !faraday.Running {
-				return fmt.Errorf("faraday has not yet started")
+			if !ok {
+				return fmt.Errorf("faraday status not found")
+			}
+			if faraday.Error != "" {
+				return fmt.Errorf("faraday failed to "+
+					"start: %s", faraday.Error)
 			}
 		}
 
 		if loopMode != terminal.ModeDisable {
 			loop, ok := states.SubServers[subservers.LOOP]
-			if !ok || !loop.Running {
-				return fmt.Errorf("loop has not yet started")
+			if !ok {
+				return fmt.Errorf("loop status not found")
+			}
+			if loop.Error != "" {
+				return fmt.Errorf("loop failed to "+
+					"start: %s", loop.Error)
 			}
 		}
 
 		if poolMode != terminal.ModeDisable {
 			pool, ok := states.SubServers[subservers.POOL]
-			if !ok || !pool.Running {
-				return fmt.Errorf("pool has not yet started")
+			if !ok {
+				return fmt.Errorf("pool status not found")
+			}
+			if pool.Error != "" {
+				return fmt.Errorf("pool failed to "+
+					"start: %s", pool.Error)
 			}
 		}
 
 		if tapMode != terminal.ModeDisable {
 			tap, ok := states.SubServers[subservers.TAP]
-			if !ok || !tap.Running {
-				return fmt.Errorf("tap has not yet started")
+			if !ok {
+				return fmt.Errorf("tap status not found")
+			}
+			if tap.Error != "" {
+				return fmt.Errorf("tap failed to "+
+					"start: %s", tap.Error)
 			}
 		}
 

lnd_ready.go

@@ -0,0 +1,54 @@
+package terminal
+
+import (
+	"context"
+	"fmt"
+	"time"
+
+	"github.com/lightningnetwork/lnd/lnrpc"
+)
+
+// waitForLndRPCReady polls lnd's StateService until lnd's RPC interceptor has
+// left the WAITING_TO_START state, or timeout elapses. Unlike every other
+// lnd RPC, the StateService is exempt from both lnd's macaroon check and its
+// RPC-readiness check (see lnd's rpcperms.InterceptorChain), so it can be
+// queried on a fresh connection before the wallet is unlocked and before any
+// macaroon exists. This lets us distinguish lnd's gRPC listener merely being
+// bound (which is all readyChan/unlockChan guarantee) from lnd actually being
+// able to service non-State RPCs.
+func waitForLndRPCReady(ctx context.Context, stateClient lnrpc.StateClient,
+	timeout time.Duration) error {
+
+	timer := time.NewTimer(timeout)
+	defer timer.Stop()
+
+	var lastErr error
+
+	for {
+		resp, err := stateClient.GetState(ctx, &lnrpc.GetStateRequest{})
+		switch {
+		case err != nil:
+			lastErr = err
+
+		case resp.State != lnrpc.WalletState_WAITING_TO_START:
+			return nil
+		}
+
+		select {
+		case <-time.After(stateServicePollInterval):
+
+		case <-timer.C:
+			if lastErr != nil {
+				return fmt.Errorf("lnd's RPC interceptor "+
+					"did not leave WAITING_TO_START "+
+					"within %v: %w", timeout, lastErr)
+			}
+
+			return fmt.Errorf("lnd's RPC interceptor did not "+
+				"leave WAITING_TO_START within %v", timeout)
+
+		case <-ctx.Done():
+			return ctx.Err()
+		}
+	}
+}

lnd_ready_test.go

@@ -0,0 +1,117 @@
+package terminal
+
+import (
+	"context"
+	"errors"
+	"testing"
+	"time"
+
+	"github.com/lightningnetwork/lnd/lnrpc"
+	"github.com/stretchr/testify/require"
+	"google.golang.org/grpc"
+)
+
+// fakeStateClient is a test-only lnrpc.StateClient that replays a canned
+// sequence of GetState responses/errors, repeating the last entry once the
+// sequence is exhausted.
+type fakeStateClient struct {
+	lnrpc.StateClient
+
+	responses []*lnrpc.GetStateResponse
+	errs      []error
+	calls     int
+}
+
+func (f *fakeStateClient) GetState(_ context.Context,
+	_ *lnrpc.GetStateRequest, _ ...grpc.CallOption) (
+	*lnrpc.GetStateResponse, error) {
+
+	idx := f.calls
+	if idx >= len(f.responses) {
+		idx = len(f.responses) - 1
+	}
+	f.calls++
+
+	return f.responses[idx], f.errs[idx]
+}
+
+// TestWaitForLndRPCReady asserts that waitForLndRPCReady correctly polls
+// lnd's StateService until it reports a state other than WAITING_TO_START,
+// and that it times out with an error if that never happens.
+func TestWaitForLndRPCReady(t *testing.T) {
+	t.Parallel()
+
+	activeResp := &lnrpc.GetStateResponse{
+		State: lnrpc.WalletState_RPC_ACTIVE,
+	}
+	waitingResp := &lnrpc.GetStateResponse{
+		State: lnrpc.WalletState_WAITING_TO_START,
+	}
+
+	testCases := []struct {
+		name        string
+		client      *fakeStateClient
+		timeout     time.Duration
+		expectError bool
+	}{
+		{
+			name: "ready immediately",
+			client: &fakeStateClient{
+				responses: []*lnrpc.GetStateResponse{
+					activeResp,
+				},
+				errs: []error{nil},
+			},
+			timeout: time.Second,
+		},
+		{
+			name: "ready after N polls",
+			client: &fakeStateClient{
+				responses: []*lnrpc.GetStateResponse{
+					waitingResp, waitingResp, activeResp,
+				},
+				errs: []error{nil, nil, nil},
+			},
+			timeout: time.Second,
+		},
+		{
+			name: "timeout without transition",
+			client: &fakeStateClient{
+				responses: []*lnrpc.GetStateResponse{
+					waitingResp,
+				},
+				errs: []error{nil},
+			},
+			timeout:     300 * time.Millisecond,
+			expectError: true,
+		},
+		{
+			name: "timeout while erroring",
+			client: &fakeStateClient{
+				responses: []*lnrpc.GetStateResponse{nil},
+				errs: []error{
+					errors.New("connection refused"),
+				},
+			},
+			timeout:     300 * time.Millisecond,
+			expectError: true,
+		},
+	}
+
+	for _, tc := range testCases {
+		tc := tc
+		t.Run(tc.name, func(t *testing.T) {
+			t.Parallel()
+
+			err := waitForLndRPCReady(
+				context.Background(), tc.client, tc.timeout,
+			)
+
+			if tc.expectError {
+				require.Error(t, err)
+				return
+			}
+			require.NoError(t, err)
+		})
+	}
+}

terminal.go

@@ -87,6 +87,10 @@ const (
 	defaultRPCTimeout     = 3 * time.Minute
 	minimumRPCTimeout     = 30 * time.Second
 	defaultStartupTimeout = 5 * time.Second
+
+	// stateServicePollInterval is how often we poll lnd's StateService
+	// while waiting for its RPC interceptor to leave WAITING_TO_START.
+	stateServicePollInterval = 200 * time.Millisecond
 )
 
 // restRegistration is a function type that represents a REST proxy
@@ -673,6 +677,22 @@ func (g *LightningTerminal) start(ctx context.Context) error {
 			err)
 	}
 
+	// The unlockChan/readyChan signal we waited on above only guarantees
+	// that lnd's gRPC listener socket is bound, not that lnd's RPC
+	// interceptor has advanced far enough to service non-State RPCs. Wait
+	// for that here so that the "Wallet Ready" status set below is not
+	// observed before it's actually true.
+	lndStateClient := lnrpc.NewStateClient(g.lndConn)
+	if err := waitForLndRPCReady(
+		ctx, lndStateClient, defaultConnectTimeout,
+	); err != nil {
+		g.statusMgr.SetErrored(
+			subservers.LND, "lnd RPC not ready: %v", err,
+		)
+
+		return fmt.Errorf("lnd RPC not ready: %v", err)
+	}
+
 	// We now set a custom status for the LND sub-server to indicate that
 	// the wallet is ready.
 	// This is done _before_ we have set up the lnd clients so that the