search

LN-Zap / zap-desktop

Zap Wallet - Cross platform Lightning Network wallet focused on user experience and ease of use ⚡️
MIT License
1.28k stars 216 forks source link

Sync process hangs at 99% for a long time when recovering a wallet whist lnd scans blocks for recoverable addresses #2080

Closed mrfelton closed 5 years ago

mrfelton commented 5 years ago

Description

Sync process hangs at 99% for a long time when recovering a wallet whist lnd scans blocks for recoverable addresses.

Expected Behavior

Sync screen should factor in the additional time it takes to scan old blocks for recoverable addresses.

Actual Behavior

Sync screen hangs at 99% whilst old blocks are scanned.

Log output from lnd shows what is happening in the background:

zap:lnd [INF]  2019-04-22 13:04:08.973 [INF] LNWL: RECOVERY MODE ENABLED -- rescanning for used addresses with recovery_window=250 +759ms
  zap:lnd [INF]  2019-04-22 13:04:08.983 [INF] LNWL: Seed birthday surpassed, starting recovery of wallet from height=567221 hash=0000000000000000002e2998f76507736d96df2f2cb45a744795d7316bea2b8a with recovery-window=250 +10ms
  zap:lnd [INF]  2019-04-22 13:04:08.996 [INF] LNWL: Scanning 780 blocks for recoverable addresses +13ms
  zap:lnd [INF]  2019-04-22 13:04:12.097 [INF] BTCN: Waiting for more block headers, then will start cfheaders sync from height 570000... +3s
  zap:lnd [INF]  2019-04-22 13:04:12.097 [INF] BTCN: Starting cfheaders sync from (block_height=570000, block_hash=0000000000000000000822cf76247f1ecec0a82dbecb3b482ec4d2d154e0cd1d) to (block_height=572746, block_hash=000000000000000000281a467a2f64f5b0283f9fd40c0bc3678776d33cf75723) +1ms
  zap:lnd [INF]  2019-04-22 13:04:12.099 [INF] BTCN: Starting cfheaders sync for filter_type=0 +2ms
  zap:lnd [INF]  2019-04-22 13:04:12.227 [INF] BTCN: Fetching set of checkpointed cfheaders filters from height=570000, hash=620f1c748b3965f3e8eed33d74bbaead8b2b584a028a7040f202277817ffbd5c +127ms
  zap:lnd [INF]  2019-04-22 13:04:12.227 [INF] BTCN: Starting to query for cfheaders from checkpoint_interval=570 +1ms
  zap:lnd [INF]  2019-04-22 13:04:12.227 [INF] BTCN: Attempting to query for 2 cfheader batches +0ms
  zap:lnd [INF]  2019-04-22 13:04:12.687 [INF] BTCN: Verified 83000 filter headers in the last 12.22s (height 570001, 2019-04-03 11:22:56 +0200 CEST) +460ms
  zap:main [INF]  Sending message to renderer process: { msg: 'lndCfilterHeight', data: 570001 } +0ms
  zap:lnd [INF]  2019-04-22 13:04:15.714 [INF] BTCN: Fully caught up with cfheaders at height 572746, waiting at tip for new blocks +3s
  zap:lnd [INF]  2019-04-22 13:04:15.715 [INF] BTCN: Attempting to fetch set of un-checkpointed filters at height=572746, hash=000000000000000000281a467a2f64f5b0283f9fd40c0bc3678776d33cf75723 +0ms
  zap:lnd [INF]  2019-04-22 13:07:07.455 [INF] LNWL: Recovered addresses from blocks 567221-568000 +3m
  zap:lnd [INF]  2019-04-22 13:07:07.613 [INF] LNWL: Scanning 2000 blocks for recoverable addresses +157ms
  zap:lnd [INF]  2019-04-22 13:08:27.351 [INF] LNWL: Fetching block height=568358 hash=0000000000000000001e2c52b041dc46c93a00a6e123ac6ff2935beb31469b90 +1m
  zap:lnd [INF]  2019-04-22 13:08:51.196 [INF] LNWL: Fetching block height=568457 hash=0000000000000000001e4cb64e17b65f2654e5807a2cb5845c3def034d8a54df +24s
  zap:lnd [INF]  2019-04-22 13:14:32.727 [INF] LNWL: Fetching block height=569987 hash=00000000000000000005f95125bd5c19e874ef3517b180c4c71f537acd529045 +6m
  zap:lnd [INF]  2019-04-22 13:14:42.384 [INF] LNWL: Recovered addresses from blocks 568001-570000 +10s
  zap:lnd [INF]  2019-04-22 13:14:42.495 [INF] LNWL: Scanning 2000 blocks for recoverable addresses +111ms
  zap:lnd [INF]  2019-04-22 13:17:59.718 [INF] LNWL: Fetching block height=570859 hash=0000000000000000002a31f50dde965d8c929e1e34be72efa3bbd791a1ea7051 +3m
  zap:lnd [INF]  2019-04-22 13:20:08.451 [INF] LNWL: Fetching block height=571439 hash=0000000000000000000f87c05c462d3874844cc161c6b0d5bc744d53c3937ef1 +2m
  zap:lnd [WRN]  2019-04-22 13:20:14.210 [WRN] LNWL: Could not parse output script in b858e36898d32ddb853875b10fe3d263524bbcb338b62b63649c000abdc1475b:2: opcode OP_DATA_75 requires 76 bytes, but script only has 39 remaining +6s
  zap:lnd [INF]  2019-04-22 13:22:17.653 [INF] LNWL: Recovered addresses from blocks 570001-572000 +2m
  zap:lnd [INF]  2019-04-22 13:22:17.777 [INF] LNWL: Scanning 746 blocks for recoverable addresses +124ms
  zap:lnd [INF]  2019-04-22 13:22:50.524 [INF] BTCN: Processed 2426 blocks in the last 18m53.68s (height 572747, 2019-04-22 13:22:23 +0200 CEST) +33s
  zap:main [INF]  Sending message to renderer process: { msg: 'lndBlockHeight', data: 572747 } +1ms
  zap:main [INF]  Sending message to renderer process: { msg: 'currentBlockHeight', data: 572747 } +0ms
  zap:lnd [INF]  2019-04-22 13:22:50.538 [INF] BTCN: Attempting to fetch set of un-checkpointed filters at height=572747, hash=0000000000000000001a82cd1b7adc2192568b26517378ff6360fd8c38cef320 +13ms
  zap:lnd [INF]  2019-04-22 13:22:51.366 [INF] BTCN: Verified 2746 filter headers in the last 18m38.64s (height 572747, 2019-04-22 13:22:23 +0200 CEST) +828ms
  zap:main [INF]  Sending message to renderer process: { msg: 'lndCfilterHeight', data: 572747 } +1ms
  zap:lnd [INF]  2019-04-22 13:25:06.420 [INF] LNWL: Recovered addresses from blocks 572001-572746 +2m
  zap:lnd [INF]  2019-04-22 13:25:06.429 [INF] LNWL: Started rescan from block 000000000000000000281a467a2f64f5b0283f9fd40c0bc3678776d33cf75723 (height 572746) for 0 addresses +9ms
  zap:lnd [INF]  2019-04-22 13:25:06.430 [INF] BTCN: Registering block subscription: id=2 +0ms
  zap:lnd [INF]  2019-04-22 13:25:06.430 [INF] BTCN: Canceling block subscription: id=2 +1ms
  zap:lnd [INF]  2019-04-22 13:25:06.431 [INF] LNWL: Catching up block hashes to height 572747, this might take a while +0ms
  zap:lnd [INF]  2019-04-22 13:25:06.431 [INF] BTCN: Registering block subscription: id=3 +1ms
  zap:lnd [INF]  2019-04-22 13:25:06.442 [INF] LNWL: Done catching up block hashes +10ms
  zap:lnd [INF]  2019-04-22 13:25:06.442 [INF] LNWL: Rescanned through block 0000000000000000001a82cd1b7adc2192568b26517378ff6360fd8c38cef320 (height 572747) +1ms
  zap:lnd [INF]  2019-04-22 13:30:03.043 [INF] BTCN: Processed 1 block in the last 7m12.53s (height 572748, 2019-04-22 13:29:26 +0200 CEST) +5m
  zap:main [INF]  Sending message to renderer process: { msg: 'lndBlockHeight', data: 572748 } +1ms
  zap:main [INF]  Sending message to renderer process: { msg: 'currentBlockHeight', data: 572748 } +1ms
  zap:lnd [INF]  2019-04-22 13:30:03.054 [INF] BTCN: Attempting to fetch set of un-checkpointed filters at height=572748, hash=000000000000000000241cd3be362ef6ad3286996db1a07002282a53f69dca2d +10ms
  zap:lnd [INF]  2019-04-22 13:30:03.346 [INF] BTCN: Verified 1 filter header in the last 7m11.99s (height 572748, 2019-04-22 13:29:26 +0200 CEST) +292ms
  zap:main [INF]  Sending message to renderer process: { msg: 'lndCfilterHeight', data: 572748 } +0ms
  zap:lnd [INF]  2019-04-22 13:30:03.347 [INF] LNWL: Catching up block hashes to height 572748, this might take a while +1ms
  zap:lnd [INF]  2019-04-22 13:30:03.358 [INF] LNWL: Done catching up block hashes +11ms
  zap:lnd [INF]  2019-04-22 13:30:03.358 [INF] LNWL: Finished rescan for 0 addresses (synced to block 000000000000000000241cd3be362ef6ad3286996db1a07002282a53f69dca2d, height 572748) +1ms
  zap:lnd [INF]  2019-04-22 13:30:04.298 [INF] LTND: Chain backend is fully synced (end_height=572748)! +938ms
  zap:main [INF]  Neutrino sync finished +1ms
  zap:main [INF]  Sending message to renderer process: { msg: 'lndSyncStatus', data: 'complete' } +0ms

Possible Fix

Factor recovery process into the sync progress calculations and progress bar display

Steps to Reproduce

Import an old wallet and monitor the lnd logs whist the sync is happening.

Your Environment

mrfelton commented 5 years ago

Closed via https://github.com/LN-Zap/zap-desktop/pull/2133