From fd7e53b9fd0c080bf56f3c76b9da2945babd2465 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Wed, 8 Oct 2025 16:10:45 +1030 Subject: [PATCH 1/3] wallet: print progress reports for large account migration. Show the work we're doing (at debug level) and every 10 seconds print progress (at INFO level):x ``` lightningd-1 2025-10-08T05:13:07.973Z INFO lightningd: Creating database lightningd-1 2025-10-08T05:13:10.987Z DEBUG lightningd: Transferring 6166 chain_events lightningd-1 2025-10-08T05:13:11.780Z DEBUG lightningd: Transferring 1660043 channel_events ``` It's the inserting channel_events which takes a long time, slowing down exponentially: ``` lightningd-1 2025-10-08T05:13:18.034Z INFO lightningd: Inserted 26690/1660043 channel_events lightningd-1 2025-10-08T05:13:28.034Z INFO lightningd: Inserted 47086/1660043 channel_events lightningd-1 2025-10-08T05:13:38.035Z INFO lightningd: Inserted 61699/1660043 channel_events lightningd-1 2025-10-08T05:13:48.035Z INFO lightningd: Inserted 73743/1660043 channel_events lightningd-1 2025-10-08T05:13:58.035Z INFO lightningd: Inserted 83244/1660043 channel_events ... lightningd-1 2025-10-08T05:35:18.286Z INFO lightningd: Inserted 466720/1660043 channel_events lightningd-1 2025-10-08T05:35:29.074Z INFO lightningd: Inserted 468437/1660043 channel_events lightningd-1 2025-10-08T05:35:39.079Z INFO lightningd: Inserted 470130/1660043 channel_events lightningd-1 2025-10-08T05:35:49.081Z INFO lightningd: Inserted 471871/1660043 channel_events ``` Signed-off-by: Rusty Russell --- wallet/account_migration.c | 21 +++++++++++++++++++++ 1 file changed, 21 insertions(+) diff --git a/wallet/account_migration.c b/wallet/account_migration.c index 60e5bced70ba..65e72e141417 100644 --- a/wallet/account_migration.c +++ b/wallet/account_migration.c @@ -87,6 +87,17 @@ struct chain_event { bool we_opened; }; +/* Every 10 seconds, give progress indication */ +static bool give_progress(struct timemono *prev) +{ + struct timemono now = time_mono(); + if (time_to_sec(timemono_between(now, *prev)) >= 10) { + *prev = now; + return true; + } + return false; +} + static struct chain_event *stmt2chain_event(const tal_t *ctx, struct db_stmt *stmt) { struct chain_event *e = tal(ctx, struct chain_event); @@ -354,6 +365,7 @@ void migrate_from_account_db(struct lightningd *ld, struct db *db) size_t descriptions_migrated = 0; struct db_stmt *stmt; int version; + struct timemono prev; /* Initialize wait indices: we're going to use it to generate ids. */ load_indexes(db, ld->indexes); @@ -379,6 +391,7 @@ void migrate_from_account_db(struct lightningd *ld, struct db *db) } /* Load events */ + prev = time_mono(); db_begin_transaction(account_db); version = db_get_version(account_db); /* -1 means empty database (Postgres usually). */ @@ -396,6 +409,8 @@ void migrate_from_account_db(struct lightningd *ld, struct db *db) db_commit_transaction(account_db); tal_free(account_db); + log_debug(ld->log, "Transferring %zu chain_events", + tal_count(chain_events)); for (size_t i = 0; i < tal_count(chain_events); i++) { const struct chain_event *ev = chain_events[i]; struct mvt_account_id *account = tal(ev, struct mvt_account_id); @@ -486,8 +501,12 @@ void migrate_from_account_db(struct lightningd *ld, struct db *db) wallet_datastore_save_utxo_description(db, &ev->outpoint, ev->desc); descriptions_migrated++; } + if (give_progress(&prev)) + log_info(ld->log, "Inserted %zu/%zu chain_events", i, tal_count(chain_events)); } + log_debug(ld->log, "Transferring %zu channel_events", + tal_count(channel_events)); for (size_t i = 0; i < tal_count(channel_events); i++) { const struct channel_event *ev = channel_events[i]; struct mvt_account_id *account = tal(ev, struct mvt_account_id); @@ -546,6 +565,8 @@ void migrate_from_account_db(struct lightningd *ld, struct db *db) wallet_datastore_save_payment_description(db, ev->payment_id, ev->desc); descriptions_migrated++; } + if (give_progress(&prev)) + log_info(ld->log, "Inserted %zu/%zu channel_events", i, tal_count(channel_events)); } log_info(ld->log, "bookkeeper migration complete: migrated %zu chainmoves, %zu channelmoves, %zu descriptions", From 3c4d210825f038c5efbe450bb11143e5f3f0af8d Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Wed, 8 Oct 2025 16:11:45 +1030 Subject: [PATCH 2/3] lightningd: explicit db arg to wait_index_increase so we can use it in migrations. Before db is complete, ld->wallet->db is NULL. Signed-off-by: Rusty Russell --- lightningd/peer_htlcs.c | 3 ++- lightningd/wait.c | 3 ++- lightningd/wait.h | 2 ++ 3 files changed, 6 insertions(+), 2 deletions(-) diff --git a/lightningd/peer_htlcs.c b/lightningd/peer_htlcs.c index 27c3a4757674..da93db881001 100644 --- a/lightningd/peer_htlcs.c +++ b/lightningd/peer_htlcs.c @@ -3059,7 +3059,8 @@ void htlcs_index_deleted(struct lightningd *ld, const struct channel *channel, u64 num_deleted) { - wait_index_increase(ld, WAIT_SUBSYSTEM_HTLCS, WAIT_INDEX_DELETED, + wait_index_increase(ld, ld->wallet->db, + WAIT_SUBSYSTEM_HTLCS, WAIT_INDEX_DELETED, num_deleted, "short_channel_id", fmt_short_channel_id(tmpctx, channel_scid_or_local_alias(channel)), NULL); diff --git a/lightningd/wait.c b/lightningd/wait.c index 4d9066f602a6..a2b25297673d 100644 --- a/lightningd/wait.c +++ b/lightningd/wait.c @@ -189,6 +189,7 @@ u64 wait_index_increment(struct lightningd *ld, } void wait_index_increase(struct lightningd *ld, + struct db *db, enum wait_subsystem subsystem, enum wait_index index, u64 num, @@ -200,7 +201,7 @@ void wait_index_increase(struct lightningd *ld, return; va_start(ap, num); - wait_index_bump(ld, ld->wallet->db, subsystem, index, num, ap); + wait_index_bump(ld, db, subsystem, index, num, ap); va_end(ap); } diff --git a/lightningd/wait.h b/lightningd/wait.h index d60abfe2c214..da71b6c2dee5 100644 --- a/lightningd/wait.h +++ b/lightningd/wait.h @@ -57,6 +57,7 @@ u64 LAST_ARG_NULL wait_index_increment(struct lightningd *ld, /** * wait_index_increase - increase an index, tell waiters. * @ld: the lightningd + * @db: the database (usually ld->wallet->db, except really early) * @subsystem: subsystem for index * @index: which index * @num: number to add (if > 0). @@ -65,6 +66,7 @@ u64 LAST_ARG_NULL wait_index_increment(struct lightningd *ld, * A more generic version if wait_index_increment: if num is 0 it's a noop. */ void LAST_ARG_NULL wait_index_increase(struct lightningd *ld, + struct db *db, enum wait_subsystem subsystem, enum wait_index index, u64 num, From cc00eec78710bbc1da30e4686c8f718204e1e18b Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Wed, 8 Oct 2025 16:15:44 +1030 Subject: [PATCH 3/3] wallet: fix migration speed for postgres. Testing a large db shows Postgres slowing down exponentially as it inserts the channel_events. Rather than updating the index in the db every time, do it at the end, for spectacular speedup: ``` lightningd-1 2025-10-08T05:39:44.333Z INFO lightningd: Creating database lightningd-1 2025-10-08T05:39:47.581Z DEBUG lightningd: Transferring 6166 chain_events lightningd-1 2025-10-08T05:39:48.455Z DEBUG lightningd: Transferring 1660043 channel_events lightningd-1 2025-10-08T05:39:54.390Z INFO lightningd: Inserted 103100/1660043 channel_events lightningd-1 2025-10-08T05:40:04.390Z INFO lightningd: Inserted 283280/1660043 channel_events lightningd-1 2025-10-08T05:40:14.390Z INFO lightningd: Inserted 464065/1660043 channel_events lightningd-1 2025-10-08T05:40:24.390Z INFO lightningd: Inserted 629559/1660043 channel_events lightningd-1 2025-10-08T05:40:34.390Z INFO lightningd: Inserted 800659/1660043 channel_events lightningd-1 2025-10-08T05:40:44.390Z INFO lightningd: Inserted 975433/1660043 channel_events lightningd-1 2025-10-08T05:40:54.390Z INFO lightningd: Inserted 1134719/1660043 channel_events lightningd-1 2025-10-08T05:41:04.390Z INFO lightningd: Inserted 1290549/1660043 channel_events lightningd-1 2025-10-08T05:41:14.390Z INFO lightningd: Inserted 1443304/1660043 channel_events lightningd-1 2025-10-08T05:41:24.390Z INFO lightningd: Inserted 1590013/1660043 channel_events lightningd-1 2025-10-08T05:41:29.148Z INFO lightningd: bookkeeper migration complete: migrated 6166 chainmoves, 1660043 channelmoves, 132481 descriptions ``` Now we complete the entire migration in 1 minute 45 seconds. Thanks to @michael1101 for reporting this. Signed-off-by: Rusty Russell Changelog-Fixed: db: migration from v25.09 on a reasonable size account database could take almost infinite time. --- wallet/account_migration.c | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/wallet/account_migration.c b/wallet/account_migration.c index 65e72e141417..e26d5211101b 100644 --- a/wallet/account_migration.c +++ b/wallet/account_migration.c @@ -366,6 +366,7 @@ void migrate_from_account_db(struct lightningd *ld, struct db *db) struct db_stmt *stmt; int version; struct timemono prev; + u64 num_channel_events; /* Initialize wait indices: we're going to use it to generate ids. */ load_indexes(db, ld->indexes); @@ -507,11 +508,13 @@ void migrate_from_account_db(struct lightningd *ld, struct db *db) log_debug(ld->log, "Transferring %zu channel_events", tal_count(channel_events)); + + /* There can be lots of these, so do a single update at the end */ + num_channel_events = 0; for (size_t i = 0; i < tal_count(channel_events); i++) { const struct channel_event *ev = channel_events[i]; struct mvt_account_id *account = tal(ev, struct mvt_account_id); enum mvt_tag tag; - u64 id; /* We removed currency support, because the only way you could * use it was to inject your own events, and nobody did that @@ -536,8 +539,7 @@ void migrate_from_account_db(struct lightningd *ld, struct db *db) " payment_group_id," " fees) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?);")); set_mvt_account_id(account, NULL, ev->acct_name); - id = channel_mvt_index_created(ld, db, account, ev->credit, ev->debit); - db_bind_u64(stmt, id); + db_bind_u64(stmt, ++num_channel_events); db_bind_mvt_account_id(stmt, db, account); db_bind_credit_debit(stmt, ev->credit, ev->debit); if (!mvt_tag_parse(ev->tag, strlen(ev->tag), &tag)) @@ -569,6 +571,12 @@ void migrate_from_account_db(struct lightningd *ld, struct db *db) log_info(ld->log, "Inserted %zu/%zu channel_events", i, tal_count(channel_events)); } + wait_index_increase(ld, db, + WAIT_SUBSYSTEM_CHANNELMOVES, + WAIT_INDEX_CREATED, + num_channel_events, + NULL); + log_info(ld->log, "bookkeeper migration complete: migrated %zu chainmoves, %zu channelmoves, %zu descriptions", tal_count(chain_events), tal_count(channel_events),