diff --git a/config.go b/config.go index fc6fd7f93..0d920a7f9 100644 --- a/config.go +++ b/config.go @@ -98,6 +98,18 @@ const ( defaultFirstLNCConnTimeout = 10 * time.Minute + // defaultLndReadyTimeout is the default maximum time that litd + // waits for lnd's RPC server to become ready. It currently applies + // to the one-time kvdb-to-SQL data migration, which must call into + // lnd's main RPC server (ListMacaroonIDs); that only becomes + // available once lnd reaches its "RPC active" state. On nodes with a + // large channel/graph state this can take well over a minute after + // the wallet is unlocked, and timing out aborts litd startup + // entirely (requiring a manual restart), so we default to a + // deliberately generous value that comfortably covers even large + // nodes. + defaultLndReadyTimeout = 10 * time.Minute + // DatabaseBackendSqlite is the name of the SQLite database backend. DatabaseBackendSqlite = "sqlite" @@ -220,6 +232,11 @@ type Config struct { // resolved. autoMigrateKVDBApproved bool + // LndReadyTimeout is the maximum time that litd will wait for lnd's RPC + // server to become ready. This currently applies to the one-time + // kvdb-to-SQL data migration, which must call into lnd's RPC. + LndReadyTimeout time.Duration `long:"lndreadytimeout" description:"The maximum time that litd will wait for lnd's RPC server to become ready. This currently applies to the one-time migration of litd's legacy kvdb data to the configured SQL backend, which must call into lnd's RPC. On nodes with a large channel and graph state, lnd can take a while to start serving RPC calls after the wallet is unlocked; increase this value if startup fails with an error mentioning that lnd's 'RPC server is in the process of starting up'."` + // Sqlite holds the configuration options for a SQLite database // backend. Sqlite *db.SqliteConfig `group:"sqlite" namespace:"sqlite"` @@ -341,6 +358,7 @@ func (c *Config) NewStores(ctx context.Context, migsets.MakeMigrationSets( ctx, basicClient, c.MacaroonPath, c.LitDir, c.Network, clock, + c.LndReadyTimeout, ), ) if err != nil { @@ -393,6 +411,7 @@ func (c *Config) NewStores(ctx context.Context, migsets.MakeMigrationSets( ctx, basicClient, c.MacaroonPath, c.LitDir, c.Network, clock, + c.LndReadyTimeout, ), ) if err != nil { @@ -539,6 +558,7 @@ func defaultConfig() *Config { Lnd: &lndDefaultConfig, LndRPCTimeout: defaultRPCTimeout, LndConnectInterval: defaultStartupTimeout, + LndReadyTimeout: defaultLndReadyTimeout, LitDir: DefaultLitDir, LetsEncryptListen: defaultLetsEncryptListen, LetsEncryptDir: defaultLetsEncryptDir, @@ -673,6 +693,15 @@ func loadAndValidateConfig(ctx context.Context, "to avoid problems", minimumRPCTimeout) } + // The work that waits on lnd's readiness (currently the kvdb-to-SQL + // migration) cannot proceed without lnd, so a non-positive timeout + // would make it fail immediately on any node where lnd isn't + // instantly ready. Require a positive value. + if cfg.LndReadyTimeout <= 0 { + return nil, fmt.Errorf("lndreadytimeout must be positive, got "+ + "%v", cfg.LndReadyTimeout) + } + // Validate the lightning-terminal config options. litDir := lnd.CleanAndExpandPath(preCfg.LitDir) cfg.LetsEncryptDir = lncfg.CleanAndExpandPath(cfg.LetsEncryptDir) diff --git a/db/migsets/programmatic_migrations.go b/db/migsets/programmatic_migrations.go index 585bf016d..eb372fcc5 100644 --- a/db/migsets/programmatic_migrations.go +++ b/db/migsets/programmatic_migrations.go @@ -26,7 +26,8 @@ import ( func Mig6ProgrammaticMigration(ctx context.Context, basicClient lnrpc.LightningClient, db *sqldb.BaseDB, accountsDir, networkDir string, clock clock.Clock, - migVersion uint) migrate.ProgrammaticMigrEntry { + migVersion uint, + lndReadyTimeout time.Duration) migrate.ProgrammaticMigrEntry { mig6queries := sqlcmig6.NewForType(db, db.BackendType) mig6executor := sqldb.NewTransactionExecutor( @@ -49,6 +50,7 @@ func Mig6ProgrammaticMigration(ctx context.Context, return kvdbToSqlProgrammaticMigration( ctx, basicClient, accountsDir, networkDir, db, clock, q6, + lndReadyTimeout, ) }, sqldb.NoOpReset, ) @@ -87,7 +89,8 @@ func Mig6ProgrammaticMigration(ctx context.Context, func kvdbToSqlProgrammaticMigration(ctx context.Context, basicClient lnrpc.LightningClient, accountsDir, networkDir string, - _ *sqldb.BaseDB, clock clock.Clock, q *sqlcmig6.Queries) error { + _ *sqldb.BaseDB, clock clock.Clock, q *sqlcmig6.Queries, + lndReadyTimeout time.Duration) error { start := time.Now() @@ -185,19 +188,40 @@ func kvdbToSqlProgrammaticMigration(ctx context.Context, } }() - // We'll fetch the macaroonIDList from `lnd` next. Note that since lnd's - // RPC servers may not have been fully started yet if the execution of - // accounts and session migration were really quick, we poll the request - // up to 120 times with a 0.5 second delay between the attempts. This - // should be a sufficient amount of time for the wallet to have been - // loaded and for the RPC servers to started. - const ( - maxListMacaroonIDAttempts = 120 - listMacaroonIDRetryDelay = 500 * time.Millisecond + // We'll fetch the macaroonIDList from lnd next. This is a call to + // lnd's main Lightning RPC server, which only starts accepting calls + // once lnd has reached its "RPC active" state. On nodes with a large + // channel and graph state, reaching that state can take well over a + // minute after the wallet is unlocked (opening the main database and + // building all of lnd's subsystems is slow), so we cannot assume lnd + // is ready by the time the (fast) accounts and session migrations + // above have completed. We therefore poll the request, retrying + // every listMacaroonIDRetryDelay, until lnd becomes ready, the + // lndReadyTimeout budget is exhausted, or the daemon shuts down (ctx + // canceled). + // + // NOTE: lndReadyTimeout is intentionally generous rather than a + // tight bound (see its default in the main config). litd cannot + // complete this migration without lnd, so timing out here aborts + // litd startup entirely and forces a manual restart; waiting longer + // for a slow-but-healthy lnd is strictly preferable to that. + // + // listMacaroonIDRetryDelay is the delay between successive attempts + // to reach lnd. 500ms keeps the poll responsive (lnd is typically + // ready within a minute or two) without busy-looping against a + // not-yet-ready RPC server. + const listMacaroonIDRetryDelay = 500 * time.Millisecond + + waitCtx, cancel := context.WithTimeout(ctx, lndReadyTimeout) + defer cancel() + + var ( + macaroonIDList *lnrpc.ListMacaroonIDsResponse + attempt int ) + for { + attempt++ - var macaroonIDList *lnrpc.ListMacaroonIDsResponse - for i := 1; i <= maxListMacaroonIDAttempts; i++ { macaroonIDList, err = basicClient.ListMacaroonIDs( ctx, &lnrpc.ListMacaroonIDsRequest{}, ) @@ -205,21 +229,18 @@ func kvdbToSqlProgrammaticMigration(ctx context.Context, break } - if i == maxListMacaroonIDAttempts { - return fmt.Errorf("error listing macaroon IDs when "+ - "migrating stores to SQL after %d attempts: %w", - maxListMacaroonIDAttempts, err) - } - log.Warnf("Failed to list macaroon IDs when migrating "+ - "stores to SQL (attempt %d/%d), retrying in %v: %v", - i, maxListMacaroonIDAttempts, listMacaroonIDRetryDelay, - err) + "stores to SQL (attempt %d), retrying in %v: %v", + attempt, listMacaroonIDRetryDelay, err) select { - case <-ctx.Done(): - return fmt.Errorf("context canceled while retrying "+ - "to list macaroon IDs: %w", ctx.Err()) + case <-waitCtx.Done(): + return fmt.Errorf("error listing macaroon IDs "+ + "when migrating stores to SQL after %d "+ + "attempts (waited up to %v for lnd's RPC "+ + "server to become ready): %w", attempt, + lndReadyTimeout, err) + case <-time.After(listMacaroonIDRetryDelay): } } diff --git a/db/migsets/programmatic_migrations_test.go b/db/migsets/programmatic_migrations_test.go index 49d3b1102..483cb0192 100644 --- a/db/migsets/programmatic_migrations_test.go +++ b/db/migsets/programmatic_migrations_test.go @@ -22,6 +22,12 @@ import ( "google.golang.org/grpc/test/bufconn" ) +// testLndReadyTimeout is the lnd RPC-ready timeout used for the migration in +// these tests. The test lnd server is ready immediately, so any positive value +// works; we use a short one so a broken poll loop fails fast rather than +// hanging the test. +const testLndReadyTimeout = 5 * time.Second + // TestKVDBToSQLProgrammaticMigrationSkipsMissingStores verifies that the kvdb // to SQL migration does not create missing legacy kvdb files while scanning for // stores to migrate. @@ -39,6 +45,7 @@ func TestKVDBToSQLProgrammaticMigrationSkipsMissingStores(t *testing.T) { err := kvdbToSqlProgrammaticMigration( context.Background(), nil, accountsDir, networkDir, sqlStore.BaseDB, clock.NewDefaultClock(), queries, + testLndReadyTimeout, ) require.NoError(t, err) @@ -77,6 +84,7 @@ func TestKVDBToSQLProgrammaticMigrationRunsWithOneBBoltDBFiles(t *testing.T) { err = kvdbToSqlProgrammaticMigration( ctx, lndClient, accountsDir, networkDir, sqlStore.BaseDB, testClock, queries, + testLndReadyTimeout, ) require.NoError(t, err) diff --git a/db/migsets/sql_migrations.go b/db/migsets/sql_migrations.go index 6fde04ac4..f3164be54 100644 --- a/db/migsets/sql_migrations.go +++ b/db/migsets/sql_migrations.go @@ -5,6 +5,7 @@ package migsets import ( "context" "path/filepath" + "time" "github.com/golang-migrate/migrate/v4" "github.com/golang-migrate/migrate/v4/database/pgx/v5" @@ -16,8 +17,8 @@ import ( // MakeMigrationSets creates the migration sets for production environments. func MakeMigrationSets(ctx context.Context, basicClient lnrpc.LightningClient, - macPath, litDir, network string, - clock clock.Clock) []sqldb.MigrationSet { + macPath, litDir, network string, clock clock.Clock, + lndReadyTimeout time.Duration) []sqldb.MigrationSet { accountsDir := filepath.Dir(macPath) networkDir := filepath.Join(litDir, network) @@ -50,6 +51,7 @@ func MakeMigrationSets(ctx context.Context, basicClient lnrpc.LightningClient, res[db.KVDBtoSQLMigVersion] = Mig6ProgrammaticMigration( ctx, basicClient, baseDB, accountsDir, networkDir, clock, db.KVDBtoSQLMigVersion, + lndReadyTimeout, ) return res, nil diff --git a/db/migsets/sql_migrations_dev.go b/db/migsets/sql_migrations_dev.go index 569eae338..8d703da8e 100644 --- a/db/migsets/sql_migrations_dev.go +++ b/db/migsets/sql_migrations_dev.go @@ -5,6 +5,7 @@ package migsets import ( "context" "path/filepath" + "time" "github.com/golang-migrate/migrate/v4" "github.com/golang-migrate/migrate/v4/database/pgx/v5" @@ -17,7 +18,8 @@ import ( // MakeMigrationSets creates the migration sets for the dev environments. func MakeMigrationSets(ctx context.Context, basicClient lnrpc.LightningClient, macPath, litDir, network string, - clock clock.Clock) []sqldb.MigrationSet { + clock clock.Clock, + lndReadyTimeout time.Duration) []sqldb.MigrationSet { accountsDir := filepath.Dir(macPath) networkDir := filepath.Join(litDir, network) @@ -49,6 +51,7 @@ func MakeMigrationSets(ctx context.Context, res[db.KVDBtoSQLMigVersion] = Mig6ProgrammaticMigration( ctx, basicClient, baseDB, accountsDir, networkDir, clock, db.KVDBtoSQLMigVersion, + lndReadyTimeout, ) return res, nil diff --git a/docs/release-notes/release-notes-0.17.1.md b/docs/release-notes/release-notes-0.17.1.md index 6627288ed..35ca4d1b6 100644 --- a/docs/release-notes/release-notes-0.17.1.md +++ b/docs/release-notes/release-notes-0.17.1.md @@ -23,6 +23,17 @@ `WAITING_TO_START` state, so the very next call could still fail with `rpc error: ... waiting to start`. +* [Wait longer for lnd during the kvdb-to-SQL + migration](https://github.com/lightninglabs/lightning-terminal/pull/1359): + The kvdb-to-SQL data migration polls lnd's `ListMacaroonIDs` RPC, which only + becomes available once lnd reaches its "RPC active" state. On nodes with a + large channel/graph state, lnd can take well over a minute to get there after + the wallet is unlocked, which exceeded the previous fixed 60-second poll + budget and caused the migration (and therefore litd startup) to fail + permanently, requiring a manual restart. The wait is now bounded by a + configurable, generous timeout (`--lndreadytimeout`, defaulting to 10 + minutes) instead of a fixed attempt count. + ### Functional Changes/Additions ### Technical and Architectural Updates