[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: https://github.com/lightningnetwork/lnd/pull/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: https://github.com/btcsuite/btcwallet/issues/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.