[bug]: LTND: Shutting down because error in main method: unable to start server: did not get reget response before timeout

[djkarmi]

Background

lnci fails to sync and keeps restarting a few seconds after startup
during graph synchronization

Your environment

lnd v0.17.4-beta
rasbian
prune bitcoind 26

[hieblmi]

Thanks for flagging this issue. Could you attach a log of the startup here to help investigate?

[djkarmi]

[INF] LTND: Version: 0.17.4-beta commit=v0.17.4-beta, build=production, logging=default, debug>
2024-04-15 14:41:08.463 [INF] LTND: Active chain: Bitcoin (network=mainnet)
2024-04-15 14:41:08.481 [INF] RPCS: RPC server listening on 0.0.0.0:10009
2024-04-15 14:41:08.497 [INF] RPCS: gRPC proxy started at 0.0.0.0:8081
2024-04-15 14:41:08.498 [INF] LTND: Opening the main database, this might take a few minutes...
2024-04-15 14:41:08.499 [INF] LTND: Opening bbolt database, sync_freelist=false, auto_compact=false
2024-04-15 14:41:08.792 [INF] LTND: Creating local graph and channel state DB instances
2024-04-15 14:41:09.763 [INF] CHDB: Checking for schema update: latest_version=31, db_version=31
2024-04-15 14:41:09.763 [INF] CHDB: Checking for optional update: prune_revocation_log=false, db_version=empty
2024-04-15 14:41:09.763 [INF] LTND: Database(s) now open (time_to_open=1.264235836s)!
2024-04-15 14:41:09.763 [INF] LTND: We're not running within systemd or the service type is not 'notify'
2024-04-15 14:41:09.763 [INF] LTND: Waiting for wallet encryption password. Use lncli create to create a wallet, `ln>
2024-04-15 14:41:36.125 [INF] LNWL: Opened wallet
2024-04-15 14:41:36.328 [INF] CHRE: Primary chain is set to: bitcoin
2024-04-15 14:41:36.352 [INF] LNWL: Started listening for bitcoind block notifications via ZMQ on 127.0.0.1:29000
2024-04-15 14:41:36.352 [INF] CHRE: Initializing bitcoind backed fee estimator in CONSERVATIVE mode
2024-04-15 14:41:36.352 [INF] LNWL: Started listening for bitcoind transaction notifications via ZMQ on 127.0.0.1:29001
2024-04-15 14:41:39.056 [INF] LNWL: The wallet has been unlocked without a time limit
2024-04-15 14:41:39.065 [INF] CHRE: LightningWallet opened
2024-04-15 14:41:39.079 [INF] SRVR: Proxying all network traffic via Tor (stream_isolation=false)! NOTE: Ensure the ba>
2024-04-15 14:41:39.086 [INF] HSWC: Cleaning circuits from disk for closed channels
2024-04-15 14:41:39.243 [INF] HSWC: Finished cleaning: num_closed_channel=273, num_circuits=0, num_keystone=0
2024-04-15 14:41:39.243 [INF] HSWC: Restoring in-memory circuit state from disk
2024-04-15 14:41:39.245 [INF] HSWC: Payment circuits loaded: num_pending=0, num_open=0
2024-04-15 14:41:39.269 [INF] LTND: Channel backup proxy channel notifier starting
2024-04-15 14:41:39.269 [INF] ATPL: Instantiating autopilot with active=true, max_channels=5, allocation=0.600000, min>
2024-04-15 14:41:39.270 [INF] LTND: We're not running within systemd or the service type is not 'notify'
2024-04-15 14:41:39.272 [INF] LTND: Waiting for chain backend to finish sync, start_height=839341
2024-04-15 14:42:01.589 [INF] LNWL: Started rescan from block 00000000000000000001f9656472d0d5c34363efd1c2966ffddb3e44>
2024-04-15 14:42:01.610 [INF] LNWL: Catching up block hashes to height 839341, this might take a while
2024-04-15 14:42:01.612 [INF] LNWL: Done catching up block hashes
2024-04-15 14:42:01.612 [INF] LNWL: Finished rescan for 1029 addresses (synced to block 00000000000000000001f9656472d0>
2024-04-15 14:42:02.373 [INF] LTND: Chain backend is fully synced (end_height=839341)!
2024-04-15 14:42:02.374 [WRN] HLCK: check: disk space configured with 0 attempts, skipping it
2024-04-15 14:42:02.374 [WRN] HLCK: check: tls configured with 0 attempts, skipping it
2024-04-15 14:42:02.374 [INF] LNWL: SigPool starting
2024-04-15 14:42:02.389 [INF] CHNF: ChannelNotifier starting
2024-04-15 14:42:02.389 [INF] NTFN: New block epoch subscription
2024-04-15 14:42:02.389 [INF] PRNF: PeerNotifier starting
2024-04-15 14:42:02.389 [INF] BTCN: Broadcaster now active
2024-04-15 14:42:02.389 [INF] HSWC: HtlcNotifier starting
2024-04-15 14:42:02.389 [INF] SWPR: Sweeper starting
2024-04-15 14:42:02.389 [INF] UTXN: UTXO nursery starting
2024-04-15 14:42:02.389 [INF] NTFN: New block epoch subscription
2024-04-15 14:42:02.548 [INF] NTFN: New block epoch subscription
2024-04-15 14:42:02.548 [INF] BRAR: Breach arbiter starting
2024-04-15 14:42:02.702 [INF] FNDG: Funding manager starting
2024-04-15 14:42:02.702 [INF] BRAR: Starting contract observer, watching for breaches.
2024-04-15 14:42:02.710 [WRN] LTND: Error while broadcasting transaction: mempool fee not met: -26: mempool min fee no>
2024-04-15 14:42:02.718 [INF] LNWL: Inserting unconfirmed transaction fa125065d333b8f05bd7e726cc4cd25015c118a4c1e327da>
2024-04-15 14:42:02.739 [INF] LNWL: fa125065d333b8f05bd7e726cc4cd25015c118a4c1e327d: broadcast failed>
2024-04-15 14:42:02.743 [INF] LNWL: Removed invalid transaction: fa125065d333b8f05bd7e726cc4cd25015c118a4c1e327da4400b>
2024-04-15 14:42:02.743 [ERR] FNDG: Unable to rebroadcast funding tx 020000000001011bfe62b4c9ab
2024-04-15 14:42:02.743 [INF] NTFN: New confirmation subscription: conf_id=1, txid=fa125065d333b8f05bd7e726cc4cd25015c>
2024-04-15 14:42:02.744 [INF] FNDG: Waiting for funding tx (fa125065d333b8f05bd7e726cc4cd25015c118a4c1e327da4400bcde99>
2024-04-15 14:42:02.748 [WRN] LTND: Error while broadcasting transaction: mempool fee not met: -26: mempool min fee no>
2024-04-15 14:42:02.757 [INF] LNWL: Inserting unconfirmed transaction 6a49ded9ce20f1c768c8e7e17bdb70db6d4ba74685028c5e>
2024-04-15 14:42:02.764 [INF] LNWL: 6a49ded9ce20f1c768c8e7e17bdb70db6d4ba74685028c5ef5e1e0063f91da96: broadcast failed>
2024-04-15 14:42:02.767 [INF] LNWL: Removed invalid transaction: 6a49ded9ce20f1c768c8e7e17bdb70db6d4ba74685028c5ef5e1e>
2024-04-15 14:42:02.767 [ERR] FNDG: Unable to rebroadcast funding tx 02000000000105784cceabdce67d6c046d26a51b3a0538bb9>
2024-04-15 14:42:02.767 [INF] NTFN: New confirmation subscription: conf_id=2, txid=6a49ded9ce20f1c768c8e7e17bdb70db6d4>
2024-04-15 14:42:02.768 [INF] FNDG: Waiting for funding tx (6a49ded9ce20f1c768c8e7e17bdb70db6d4ba74685028c5ef5e1e0063f>
2024-04-15 14:42:03.033 [WRN] LTND: Error while broadcasting transaction: mempool fee not met: -26: mempool min fee no>
2024-04-15 14:42:03.042 [INF] LNWL: Inserting unconfirmed transaction c651ed6d292e8afac41851f736f2f75531d967361ebb9979>
2024-04-15 14:42:03.047 [INF] LNWL: c651ed6d292e8afac41851f736f2f75531d967361ebb997919f7f058d82bd41f: broadcast failed>
2024-04-15 14:42:03.050 [INF] LNWL: Removed invalid transaction: c651ed6d292e8afac41851f736f2f75531d967361ebb997919f7f>
2024-04-15 14:42:03.050 [ERR] FNDG: Unable to rebroadcast funding tx 02000000000102789e4cff0d6886de1150ceafc09f93d6ee3>
2024-04-15 14:42:03.051 [INF] HSWC: HTLC Switch starting
2024-04-15 14:42:03.056 [INF] NTFN: New confirmation subscription: conf_id=3, txid=c651ed6d292e8afac41851f736f2f75531d>
2024-04-15 14:42:03.056 [INF] NTFN: New block epoch subscription
2024-04-15 14:42:03.056 [INF] NTFN: New block epoch subscription
2024-04-15 14:42:03.057 [INF] CNCT: ChainArbitrator starting
2024-04-15 14:42:03.062 [INF] CNCT: Creating ChannelArbitrators for 6 active channels
2024-04-15 14:42:03.063 [INF] FNDG: Waiting for funding tx
2024-04-15 14:42:03.252 [INF] NTFN: New spend subscription: spend_id=2, outpoint=c651ed6d292e8afac41851f736f2f75531d96>
2024-04-15 14:42:03.253 [INF] NTFN: Dispatching historical spend rescan for outpoint=c651ed6d292e8afac41851f736f2f7553>
2024-04-15 14:42:03.253 [INF] NTFN: New spend subscription: spend_id=4, outpoint=6d9aca0ff7f7fddeab5388e25e0a57aaee1f5>
2024-04-15 14:42:03.253 [INF] NTFN: Dispatching historical spend rescan for outpoint=6d9aca0ff7f7fddeab5388e25e0a57aae>
2024-04-15 14:42:03.253 [INF] NTFN: New spend subscription: spend_id=5, outpoint=d7091ff6b5207c3e40d4ddffa45f79c5983cf>
2024-04-15 14:42:03.253 [INF] NTFN: Dispatching historical spend rescan for outpoint=d7091ff6b5207c3e40d4ddffa45f79c59>
2024-04-15 14:42:03.254 [INF] NTFN: New spend subscription: spend_id=1, outpoint=bb12086fa917eb5a9fca0fe00127c8f87274f>
2024-04-15 14:42:03.254 [INF] NTFN: Dispatching historical spend rescan for outpoint=bb12086fa917eb5a9fca0fe00127c8f87>
2024-04-15 14:42:03.254 [INF] NTFN: New spend subscription: spend_id=3, outpoint=fa125065d333b8f05bd7e726cc4cd25015c11>
2024-04-15 14:42:03.254 [INF] NTFN: Dispatching historical spend rescan for outpoint=fa125065d333b8f05bd7e726cc4cd2501>
2024-04-15 14:42:03.254 [INF] NTFN: New spend subscription: spend_id=6, outpoint=6a49ded9ce20f1c768c8e7e17bdb70db6d4ba>
2024-04-15 14:42:03.254 [INF] NTFN: Dispatching historical spend rescan for outpoint=6a49ded9ce20f1c768c8e7e17bdb70db6>
2024-04-15 14:42:03.275 [INF] CNCT: Close observer for ChannelPoint(c651ed6d292e8afac41851f736f2f75531d967361ebb997919>
2024-04-15 14:42:03.277 [INF] CNCT: Close observer for ChannelPoint(fa125065d333b8f05bd7e726cc4cd25015c118a4c1e327da44>
2024-04-15 14:42:03.279 [INF] CNCT: Close observer for ChannelPoint(6a49ded9ce20f1c768c8e7e17bdb70db6d4ba74685028c5ef5>
2024-04-15 14:42:03.281 [INF] NTFN: Historical spend dispatch finished for request outpoint=c651ed6d292e8afac41851f736>
2024-04-15 14:42:03.282 [INF] CNCT: Close observer for ChannelPoint(d7091ff6b5207c3e40d4ddffa45f79c5983cf861cf68948772>
2024-04-15 14:42:03.284 [INF] NTFN: Historical spend dispatch finished for request outpoint=fa125065d333b8f05bd7e726cc>
2024-04-15 14:42:03.286 [INF] NTFN: Historical spend dispatch finished for request outpoint=6a49ded9ce20f1c768c8e7e17b>
2024-04-15 14:42:03.295 [INF] CNCT: Close observer for ChannelPoint(6d9aca0ff7f7fddeab5388e25e0a57aaee1f59fc71d745d9d6>
2024-04-15 14:42:03.308 [INF] CNCT: Close observer for ChannelPoint(bb12086fa917eb5a9fca0fe00127c8f87274f6f3d3da1ebb3d>
2024-04-15 14:42:03.311 [INF] CNCT: ChannelArbitrator(6d9aca0ff7f7fddeab5388e25e0a57aaee1f59fc71d745d9d67fa6908af622b8>
2024-04-15 14:42:03.313 [INF] CNCT: ChannelArbitrator(d7091ff6b5207c3e40d4ddffa45f79c5983cf861cf689487728412cc2996c429
2024-04-15 14:42:03.322 [INF] CNCT: ChannelArbitrator(c651ed6d292e8afac41851f736f2f75531d967361ebb997919f7f058d82bd41f>
2024-04-15 14:42:03.322 [INF] DISC: Authenticated Gossiper starting
2024-04-15 14:42:03.323 [INF] NTFN: New block epoch subscription
2024-04-15 14:42:03.323 [INF] NTFN: New block epoch subscription
2024-04-15 14:42:03.325 [INF] CRTR: Channel Router starting
2024-04-15 14:42:03.328 [INF] CRTR: FilteredChainView starting
2024-04-15 14:42:03.851 [INF] CRTR: Filtering chain using 25789 channels active
2024-04-15 14:42:03.858 [INF] CRTR: Prune tip for Channel Graph: height=814211, hash=00000000000000000002ed67aca6eb60a>
2024-04-15 14:42:03.860 [INF] CRTR: Syncing channel graph from height=814211 (hash=00000000000000000002ed67aca6eb60a99>
2024-04-15 14:42:05.874 [WRN] LNWL: Query(0) from peer 93.218.187.139:8333 failed, rescheduling: did not get response >
2024-04-15 14:42:09.878 [WRN] LNWL: Query(0) from peer 116.251.216.176:8333 failed and reached maximum number of retri>
2024-04-15 14:42:09.878 [INF] DISC: Authenticated gossiper shutting down
2024-04-15 14:42:09.878 [INF] DISC: Authenticated Gossiper is stopping
2024-04-15 14:42:09.878 [INF] NTFN: Cancelling epoch notification, epoch_id=7
2024-04-15 14:42:09.878 [INF] DISC: Authenticated Gossiper stopped
2024-04-15 14:42:09.878 [INF] CNCT: ChainArbitrator shutting down
2024-04-15 14:42:09.878 [INF] NTFN: Cancelling epoch notification, epoch_id=6
2024-04-15 14:42:09.879 [INF] NTFN: Cancelling epoch notification, epoch_id=5
2024-04-15 14:42:09.879 [INF] HSWC: HTLC Switch shutting down
2024-04-15 14:42:09.879 [INF] NTFN: Cancelling epoch notification, epoch_id=4
2024-04-15 14:42:09.879 [INF] FNDG: Funding manager shutting down
2024-04-15 14:42:09.879 [ERR] FNDG: Unable to advance pending state of ChannelPoint(fa125065d333b8f05bd7e726cc4cd25015>
2024-04-15 14:42:09.879 [WRN] FNDG: fundingManager shutting down, stopping funding flow for ChannelPoint(c651ed6d292e8>
2024-04-15 14:42:09.879 [ERR] FNDG: Unable to advance pending state of ChannelPoint(c651ed6d292e8afac41851f736f2f75531>
2024-04-15 14:42:09.879 [WRN] FNDG: fundingManager shutting down, stopping funding flow for ChannelPoint(6a49ded9ce20f>
2024-04-15 14:42:09.880 [ERR] FNDG: Unable to advance pending state of ChannelPoint(6a49ded9ce20f1c768c8e7e17bdb70db6d>
2024-04-15 14:42:09.880 [WRN] FNDG: fundingManager shutting down, stopping funding flow for ChannelPoint(fa125065d333b>
2024-04-15 14:42:09.880 [INF] BRAR: Breach arbiter shutting down
2024-04-15 14:42:09.880 [INF] UTXN: UTXO nursery shutting down
2024-04-15 14:42:09.880 [INF] NTFN: Cancelling epoch notification, epoch_id=3
2024-04-15 14:42:09.880 [INF] SWPR: Sweeper shutting down
2024-04-15 14:42:09.880 [INF] NTFN: Cancelling epoch notification, epoch_id=2
2024-04-15 14:42:09.880 [INF] HSWC: HtlcNotifier shutting down
2024-04-15 14:42:09.880 [INF] PRNF: PeerNotifier shutting down
2024-04-15 14:42:09.880 [INF] CHNF: ChannelNotifier shutting down
2024-04-15 14:42:09.880 [INF] NTFN: bitcoind notifier shutting down
2024-04-15 14:42:09.881 [INF] NTFN: Stopping mempool notifier
2024-04-15 14:42:09.881 [INF] HLCK: Health monitor shutting down
2024-04-15 14:42:09.881 [ERR] LTND: Shutting down because error in main method: unable to start server: did not get re>
2024-04-15 14:42:09.881 [INF] RPCS: Stopping RPC Server
2024-04-15 14:42:09.881 [INF] RPCS: Stopping WalletKitRPC Sub-RPC Server
2024-04-15 14:42:09.881 [INF] RPCS: Stopping WatchtowerRPC Sub-RPC Server
2024-04-15 14:42:09.881 [INF] RPCS: Stopping InvoicesRPC Sub-RPC Server
2024-04-15 14:42:09.881 [INF] RPCS: Stopping ChainRPC Sub-RPC Server
2024-04-15 14:42:09.881 [INF] RPCS: Stopping NeutrinoKitRPC Sub-RPC Server
2024-04-15 14:42:09.881 [INF] RPCS: Stopping SignRPC Sub-RPC Server
2024-04-15 14:42:09.881 [INF] RPCS: Stopping VersionRPC Sub-RPC Server
2024-04-15 14:42:09.881 [INF] RPCS: Stopping AutopilotRPC Sub-RPC Server
2024-04-15 14:42:09.882 [INF] RPCS: Stopping RouterRPC Sub-RPC Server
2024-04-15 14:42:09.882 [INF] RPCS: Stopping PeersRPC Sub-RPC Server
2024-04-15 14:42:09.882 [INF] RPCS: Stopping WatchtowerClientRPC Sub-RPC Server
2024-04-15 14:42:09.924 [INF] LTND: Shutdown complete

[ziggie1984]

ties to this: #8497, make sure you have enough stable bitcoin peers (not lightning peers) which can serve block requests which are already pruned by your node.

A more forgiving algorithm will be implemented soon see also: btcsuite/btcwallet#904

[saubyk]

make sure you have enough stable bitcoin peers (not lightning peers) which can serve block requests which are already pruned by your node

Given this explanation, can we close this issue?

[ziggie1984]

LND requires a stable set of bitcoind peers when running in pruned mode which can serve block requests when those are already purged from the local bitcoin node. In LND 19, bitcoin peers will be treated more forgiving when they cannot supply the block requests in a predefined period of time.