server is still in the process of starting

[hax0rbana-adam]

Background

I'm connecting to a bitcoind instance which is running locally.

This server was offline for a few weeks and when I brought it back up, it synced up with the chain data, but I'm still unable to connect to a peer because LND thinks it is still starting.

Error

The error about a bitcoind peer not responding seems to be a red herring, as that was not present after restarting LND, but the "server is still in the process of starting" problem remains.

Before LND restart

2025-04-21 12:57:04.092 [INF] LNWL: Started rescan from block 00000000000000000001a245451acc480b79f62d7ba164b478e2692fd6fb80cb (height 836921) for 0 addresses
2025-04-21 12:57:34.131 [WRN] LNWL: Query(20) from peer 142.132.135.175:8333 failed, rescheduling: did not get response before timeout
...
2025-04-21 12:58:25.623 [WRN] LNWL: Query(41) from peer 142.132.135.175:8333 failed, rescheduling: did not get response before timeout
2025-04-21 12:58:29.625 [WRN] LNWL: Query(41) from peer 142.132.135.175:8333 failed and reached maximum number of retries, not rescheduling: did not get response before timeout
2025-04-21 12:58:29.625 [ERR] LNWL: Unable to complete chain rescan: did not get response before timeout
2025-04-21 12:58:40.241 [ERR] RPCS: [/lnrpc.Lightning/ConnectPeer]: server is still in the process of starting

I don't know anything about this 142.132.135.175:8333 node. That is not mine. I do not have port 8333 forwarded. I'm relying on outgoing connections for my bitcoind node.

I'm also not sure why LND is not just using 127.0.0.1 for syncing the chain backend. Here's what I have in my lnd.conf:

[Bitcoind]
bitcoind.dir=/data/bitcoin
bitcoind.config=/etc/bitcoin/bitcoin.conf
bitcoind.rpchost=127.0.0.1
bitcoind.zmqpubrawblock=tcp://127.0.0.1:28332
bitcoind.zmqpubrawtx=tcp://127.0.0.1:28333

After LND restart

I restarted the LND service and unlocked the wallet and found that the server still thinks that it is not started up. I see "Waiting for chain backend to finish sync, start_height=893407" (which is the current block as of now) but no log message indicating that it has acknowledged that it has completed the chain backend sync.

025-04-21 13:49:08.271 [INF] HSWC: Cleaning circuits from disk for closed channels
2025-04-21 13:49:08.271 [INF] HSWC: Finished cleaning: no closed channels found, no actions taken.
2025-04-21 13:49:08.271 [INF] HSWC: Restoring in-memory circuit state from disk
2025-04-21 13:49:08.272 [INF] HSWC: Payment circuits loaded: num_pending=0, num_open=0
2025-04-21 13:49:08.274 [INF] CRTR: Loaded 0 mission control entries
2025-04-21 13:49:08.275 [INF] LTND: Channel backup proxy channel notifier starting
2025-04-21 13:49:08.275 [INF] ATPL: Instantiating autopilot with active=false, max_channels=5, allocation=0.600000, min_chan_size=20000, max_chan_size=16777215, private=false, min_confs=1, conf_target=3
2025-04-21 13:49:08.276 [INF] LTND: Systemd was notified about our readiness
2025-04-21 13:49:08.279 [INF] INVC: New invoice subscription client: id=1
2025-04-21 13:49:08.280 [INF] LTND: Waiting for chain backend to finish sync, start_height=893407
2025-04-21 13:49:09.273 [INF] LNWL: Started rescan from block 00000000000000000001a6dcd2513c688ad2eb03d39ac0b9ea2b3f9622197582 (height 836962) for 0 addresses
2025-04-21 13:50:08.609 [ERR] RPCS: [/lnrpc.Lightning/ConnectPeer]: server is still in the process of starting
2025-04-21 13:56:39.461 [ERR] RPCS: [/lnrpc.Lightning/ConnectPeer]: server is still in the process of starting

As shown in the logs, I left it sit for 6 minutes to see if it was possibly doing something in the background and just needed a minute to complete.

Debugging

The bitcoin node is up to date with the chain (the latest block at this time is 893407, which I double checked against mempool.space.

bitcoin-cli --rpcuser=REDACTED --rpcpassword=REDACTED getblockcount
893407

LND also seems to acknowledge this:

lncli getinfo | grep block_height
    "block_height": 893407,

And that state says it's RPC_ACTIVE

lncli state
{
    "state": "RPC_ACTIVE"
}

No additional log messages are being written to lnd.log unless I try to do a lncli connect ... again. As far as I can tell, LND isn't doing anything to continue starting up.

Question

Where do I go from here?

How can I determine if LND is really still trying to start up and what it thinks it needs to do before startup is complete?

Confusion avoidance

This issue is on a different server than the issue I've been experiencing in #9614 and I believe they are unrelated. In this ticket, I'm all caught up with the chain. In 9614, I am not all caught up with the chain and unable to sync.

[starius]

Rescanning started from height 836962, which was a while ago (~60k blocks ago). Maybe rescanning is still in progress?

While rescanning is in progress, you should receive progress notifications like "Rescanned through block ... (height ...)"
After rescanning is finished, you should receive final message "Finished rescan for ... ... (synced to block ..., height ...)".

Have you received these messages?

[hax0rbana-adam]

You are right. It seems I was just impatient. The "Rescanned through block..." messages are now appearing. Thanks for helping me know what to look for.

I'll post back after I confirm that the rescan has finished successfully and the issue has been resolved (which should be in an hour or two).

[hax0rbana-adam]

I got up to block height 890000 before getting an "Unable to complete chain rescan: did not get response before timeout" error (current block at time of writing is 893552). I restarted LND as saw it say it was starting a re-scan from block 890233, so I hope that it will complete this time around.

[hax0rbana-adam]

I was able to get the "Finished rescan ..." message in the logs. That resolves this problem.

Now I'm having the same problem as my other node, which I described in #9614 I will take the conversation over there, as it's unrelated to this thread.