[lncli] rpc error: code = Unknown desc = server is still in the process of starting

medisoft commented 4 years ago

Background

After keeping my node down for about two months, and upgrading to latest git version to ensure compatibility with bitcoin 0.20, all network tasks like open channels, close channels or adding peers throws an error

Your environment

version of lnd lncli version 0.10.99-beta commit=clock/v1.0.0-71-g87880c0d56937f2380acee37910492b2fc7b910f
which operating system (uname -a on *Nix) Linux ln-t.domitai.com 4.4.0-184-generic #214-Ubuntu SMP Thu Jun 4 10:14:11 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
version of btcd, bitcoind, or other backend bitcoin-0.20.0-x86_64-linux
any other relevant environment details running into a docker container

Steps to reproduce

I only started the node with a previous working configuration and after wallet unlock and finished sync, I run the lncli connect ... and it throws the error

Expected behaviour

Should connect or close channel or open channel

Actual behaviour

Throws an error [lncli] rpc error: code = Unknown desc = server is still in the process of starting

guggero commented 4 years ago

What's the recent log output? Is it possible lnd is still catching up blocks? Is your bitcoind fully synced?

medisoft commented 4 years ago

After 24 hours running it finally ended what it was doing. Maybe something needs more detailed error of what it is doing. Now it is working

Roasbeef commented 4 years ago

Yeah sounds like it was waiting for the bitcoind backend to finish syncing.

offerm commented 4 years ago

Facing a similar issue. Was using bitcoind before and switch to Neutrino.

lnd version 0.10.1-beta commit=v0.10.1-beta

chain sync look good

    "block_height": 636117,
    "block_hash": "0000000000000000000402ffebc23ae571164dbddc1b61797dfc28a60cdf45bf",
    "best_header_timestamp": "1592991948",
    "synced_to_chain": true,
    "synced_to_graph": false,
    "testnet": false,
    "chains": [
        {
            "chain": "bitcoin",
            "network": "mainnet"
        }
    ],

2020-06-24 06:46:35.756 [INF] RPCS: gRPC proxy started at 127.0.0.1:8080
2020-06-24 06:46:35.757 [INF] LTND: Waiting for chain backend to finish sync, start_height=636116
2020-06-24 06:46:40.172 [INF] BTCN: Verified 1 filter header in the last 2m15.08s (height 636117, 2020-06-24 06:45:48 -0300 -03)
2020-06-24 06:46:41.296 [INF] BTCN: Registering block subscription: id=2
2020-06-24 06:46:41.629 [INF] LNWL: Started rescan from block 00000000000000000007a05d3f92425a5fc61072d2272e1dc0e3f9cc27fb091a (height 633981) for 7 addresses
2020-06-24 06:46:41.630 [INF] BTCN: Canceling block subscription: id=2
2020-06-24 06:47:09.167 [INF] LNWL: Catching up block hashes to height 633982, this might take a while
2020-06-24 06:47:09.458 [INF] LNWL: Done catching up block hashes
2020-06-24 06:47:09.459 [INF] LNWL: Rescanned through block 000000000000000000025f611dd3eec1e5393d0fe1bc61e06d8a0848abc6bb90 (height 633982)
2020-06-24 06:47:52.389 [INF] BTCN: Registering block subscription: id=3
2020-06-24 06:54:39.242 [INF] LNWL: Catching up block hashes to height 636117, this might take a while
2020-06-24 06:54:39.485 [INF] LNWL: Done catching up block hashes
2020-06-24 06:54:39.486 [INF] LNWL: Finished rescan for 7 addresses (synced to block 0000000000000000000402ffebc23ae571164dbddc1b61797dfc28a60cdf45bf, height 636117)
2020-06-24 06:54:40.066 [INF] LTND: Chain backend is fully synced (end_height=636117)!
2020-06-24 06:54:40.551 [INF] BTCN: Registering block subscription: id=4
2020-06-24 06:54:40.561 [INF] PRNF: PeerNotifier starting
2020-06-24 06:54:41.026 [INF] HSWC: Starting HTLC Switch
2020-06-24 06:54:41.026 [INF] NTFN: New block epoch subscription
2020-06-24 06:54:41.026 [INF] NTFN: New block epoch subscription
2020-06-24 06:54:41.434 [INF] NTFN: New block epoch subscription
2020-06-24 06:54:41.449 [INF] NTFN: New block epoch subscription
2020-06-24 06:54:41.468 [INF] CNCT: Creating ChannelArbitrators for 3 active channels
2020-06-24 06:54:41.480 [INF] NTFN: New block epoch subscription
2020-06-24 06:54:41.480 [INF] NTFN: New block epoch subscription
2020-06-24 06:54:41.483 [INF] NTFN: New block epoch subscription
2020-06-24 06:54:41.500 [INF] NTFN: New spend subscription: spend_id=1, outpoint=40e9ded1ac4f4fd984e5ec54d9814a9d164380055e578751cd82f4813e2f259f:0, script=0 fcfca8c1251871a93e951fc581ffdc02c6ec917d00230e6cefabfcfc161b5f75, height_hint=633682
2020-06-24 06:54:41.502 [INF] NTFN: Dispatching historical spend rescan for outpoint=40e9ded1ac4f4fd984e5ec54d9814a9d164380055e578751cd82f4813e2f259f:0, script=0 fcfca8c1251871a93e951fc581ffdc02c6ec917d00230e6cefabfcfc161b5f75, start=633682, end=636117
2020-06-24 06:54:41.503 [INF] NTFN: New spend subscription: spend_id=2, outpoint=c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0, script=0 591229939cc8288fcc10b61690a1af53ef90590cfafdbfb4c88f7d6188b68ea7, height_hint=633682
2020-06-24 06:54:41.503 [INF] NTFN: Dispatching historical spend rescan for outpoint=c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0, script=0 591229939cc8288fcc10b61690a1af53ef90590cfafdbfb4c88f7d6188b68ea7, start=633682, end=636117
2020-06-24 06:54:41.503 [INF] NTFN: New spend subscription: spend_id=3, outpoint=af9bcaba1dbf7707e8f890f188323cbde8e34c16cecc08f31caa361e5c6de84f:0, script=0 6115bef7609e9e73c139246737d1999c64567a75d910c89b9cd76a527bea00e0, height_hint=633682
2020-06-24 06:54:41.504 [INF] NTFN: Dispatching historical spend rescan for outpoint=af9bcaba1dbf7707e8f890f188323cbde8e34c16cecc08f31caa361e5c6de84f:0, script=0 6115bef7609e9e73c139246737d1999c64567a75d910c89b9cd76a527bea00e0, start=633682, end=636117
2020-06-24 06:54:41.504 [INF] CNCT: Close observer for ChannelPoint(40e9ded1ac4f4fd984e5ec54d9814a9d164380055e578751cd82f4813e2f259f:0) active
2020-06-24 06:54:41.506 [INF] CNCT: Close observer for ChannelPoint(c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0) active
2020-06-24 06:54:41.506 [INF] CNCT: Close observer for ChannelPoint(af9bcaba1dbf7707e8f890f188323cbde8e34c16cecc08f31caa361e5c6de84f:0) active
2020-06-24 06:54:41.512 [INF] CNCT: ChannelArbitrator(af9bcaba1dbf7707e8f890f188323cbde8e34c16cecc08f31caa361e5c6de84f:0): starting state=StateDefault, trigger=chainTrigger, triggerHeight=636117
2020-06-24 06:54:41.514 [INF] CNCT: ChannelArbitrator(40e9ded1ac4f4fd984e5ec54d9814a9d164380055e578751cd82f4813e2f259f:0): starting state=StateDefault, trigger=chainTrigger, triggerHeight=636117
2020-06-24 06:54:41.515 [INF] CNCT: ChannelArbitrator(c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0): starting state=StateDefault, trigger=chainTrigger, triggerHeight=636117
2020-06-24 06:54:41.526 [INF] BRAR: Starting contract observer, watching for breaches.
2020-06-24 06:54:41.530 [INF] DISC: Authenticated Gossiper is starting
2020-06-24 06:54:41.531 [INF] NTFN: New block epoch subscription
2020-06-24 06:54:41.912 [INF] CRTR: FilteredChainView starting
2020-06-24 06:54:41.913 [INF] BTCN: Registering block subscription: id=5
2020-06-24 06:56:44.445 [INF] NTFN: Dispatching confirmed spend notification for outpoint=c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0, script=0 591229939cc8288fcc10b61690a1af53ef90590cfafdbfb4c88f7d6188b68ea7 at current height=636117: 91835d5dfad9ff31f5169d28dd43250e1c77ce9d39feb0385fceed9a47fd0b08[0] spending c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0 at height=635756
2020-06-24 06:56:44.475 [WRN] CNCT: Unprompted commitment broadcast for ChannelPoint(c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0) 
2020-06-24 06:56:44.476 [INF] CNCT: Remote party broadcast base set, commit_num=242
2020-06-24 06:56:44.476 [INF] CNCT: Unilateral close of ChannelPoint(c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0) detected
2020-06-24 06:56:44.487 [INF] CNCT: ChannelArbitrator(c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0): remote party has closed channel out on-chain
2020-06-24 06:56:47.902 [INF] CNCT: ChannelArbitrator(c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0): contract resolutions empty, marking channel as fully resolved!
2020-06-24 06:56:48.483 [INF] CNCT: ChannelPoint(c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0) has been fully resolved on-chain at height=635756
2020-06-24 06:56:48.483 [INF] CNCT: Marking ChannelPoint(c3ab0104aa3f7baec68f183896be76c752eb1a263d6abea02f325ca375bcc5e1:0) fully resolved
2020-06-24 06:56:48.489 [INF] CHDB: Pruning link node 03872c602d9fa9e41c80ed09fda7dd77399fe8b54b1f9fe5a658e1e89e74dc5797 with zero open channels from database
2020-06-24 06:59:19.036 [INF] CRTR: Filtering chain using 36371 channels active
2020-06-24 06:59:19.141 [INF] CRTR: Prune tip for Channel Graph: height=633682, hash=0000000000000000000a0986481251e88a8c58c539ae702d7648105e80d84ab4
2020-06-24 06:59:19.142 [INF] CRTR: Syncing channel graph from height=633682 (hash=0000000000000000000a0986481251e88a8c58c539ae702d7648105e80d84ab4) to height=636117 (hash=0000000000000000000402ffebc23ae571164dbddc1b61797dfc28a60cdf45bf)
2020-06-24 07:01:28.989 [ERR] RPCS: [/lnrpc.Lightning/ConnectPeer]: server is still in the process of starting
2020-06-24 07:03:25.141 [ERR] RPCS: [/lnrpc.Lightning/ConnectPeer]: server is still in the process of starting
2020-06-24 07:05:59.684 [ERR] RPCS: [/lnrpc.Lightning/ConnectPeer]: server is still in the process of starting

wpaulino commented 4 years ago

Are you running with routing.assumechanvalid since switching to Neutrino?

offerm commented 4 years ago

Nop. Was not even aware of this. What is the impact? show I be using it?

I switched to Neutrino as my bitcoind become not operational. It took lnd about 3 hours to sync. I had to restart for the server to become properly active. I don't have this issue any more.

Only issue that I see is

 "synced_to_graph": false,

offerm commented 4 years ago

found this from Alex's email about LND 0.8.0.

One thing is the graph sync. In the Lightning protocol, the client is assumed
to have chain data and get information about channels like the channel capacity
from there. This doesn't really fit with the Neutrino model so there is the
`assumechanvalid` configuration flag to avoid validating the graph channels.

Do I need it?

describegraph gives shows the capacity of the channels. On the other hand, I only see ~6000 channels

wpaulino commented 4 years ago

It's not required, but without it you'll be stuck syncing the whole graph for a while. Enabling it results in the capacity of channels not being known, but we can still perform pathfinding thanks to max_htlc_msat.

sandipndev commented 2 years ago

If you're on regtest, apparently you'd have to create atleast one block for lnd to turn up.

patrickikhidero commented 10 months ago

For example: use bitcoin-cli -generate 10 But make sure you have created a wallet before using the above command.

lightningnetwork / lnd