RPC services not available

[hex17or]

From the past couple of days, I have started to face an issue with my lightning terminal (especially after my upgrade to bitcoind v22.0). I am unable to unlock my lnd wallet due to "RPC services not being available". The entire console log is as below. I have also just upgraded to v0.5.1-alpha but the issue still persists. It would be great if anyone could help me understand what the issue is.

bitcoin@odroid:~/.lnd/data/chain/bitcoin/mainnet$ litd
Attempting automatic RPC configuration to bitcoind
Automatically obtained bitcoind's RPC credentials
2021-09-22 09:25:04.420 [INF] LTND: Version: 0.13.0-beta commit=lightning-terminal-v0.5.1-alpha, build=production,     logging=default, debuglevel=info
2021-09-22 09:25:04.420 [INF] LTND: Active chain: Bitcoin (network=mainnet)
2021-09-22 09:25:04.434 [INF] RPCS: RPC server listening on 127.0.0.1:10009
2021-09-22 09:25:04.434 [INF] LITD: Dialing lnd gRPC server at 127.0.0.1:10009
2021-09-22 09:25:04.444 [INF] RPCS: gRPC proxy started at 127.0.0.1:8080
2021-09-22 09:25:04.445 [INF] LTND: Opening the main database, this might take a few minutes...
2021-09-22 09:25:04.445 [INF] LTND: Opening bbolt database, sync_freelist=true, auto_compact=true
----------------------------------------------------------
 Lightning Terminal (LiT) by Lightning Labs

 Operating mode      integrated
 Node status         locked
 Alias               WingDings
 Version             0.13.0-beta
 Web interface       0.0.0.0:8443 (open https://localhost:8443 in your browser)
----------------------------------------------------------
2021-09-22 09:25:04.445 [INF] CHDB: Compacting database file at /mnt/ext/lnd/data/graph/mainnet/channel.db
2021-09-22 09:25:04.445 [INF] CHDB: Found old temp DB @ /mnt/ext/lnd/data/graph/mainnet/temp-dont-use.db, removing before swap
2021-09-22 09:25:04.445 [INF] LITD: Listening for http_tls on: [::]:8443
2021-09-22 09:25:04.671 [INF] LNDC: Creating lnd connection to 127.0.0.1:10009
2021-09-22 09:25:04.671 [INF] LNDC: Connected to lnd
2021-09-22 09:25:04.671 [INF] LNDC: Waiting for lnd to unlock
2021-09-22 09:25:04.687 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 09:25:09.688 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 09:25:14.693 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 09:25:19.694 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 09:25:24.696 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 09:25:29.701 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 09:25:34.703 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 09:25:39.706 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 09:25:42.768 [ERR] RPCS: [/lnrpc.WalletUnlocker/UnlockWallet]: waiting to start, RPC services not available
2021-09-22 09:25:44.708 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
^C2021-09-22 09:25:48.863 [INF] SGNL: Received interrupt. 
2021-09-22 09:25:48.863 [INF] SGNL: Shutting down...
2021-09-22 09:25:48.863 [INF] SGNL: Gracefully shutting down.
2021-09-22 09:25:48.864 [ERR] LITD: Could not start subservers: context canceled
^C

[guggero]

It looks like lnd is trying to compact the DB and therefore isn't ready yet. Do you use some sort of unlocking script? Normally the services within LiT should wait for lnd to fully start up (you might see the [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available error which is expected in that case). But the [/lnrpc.WalletUnlocker/UnlockWallet]: waiting to start, RPC services not available attempt to unlock isn't coming from LiT and it looks like that is somehow causing lnd to shut down.

My suggestions:

1. Disable any unlocking script or give it more time before the first attempt
2. Disable auto-compaction (db.bolt.auto-compact=false) to temporarily work around the problem.

[hex17or]

Thanks for your reply.

/lnrpc.WalletUnlocker/UnlockWallet]: waiting to start, RPC services not available is caused by me trying to unlock my wallet in another terminal session. But as you can see, the unlock does not happen and I see the same error message in the other terminal too.

I do not have any unlock script but rather unlock manually.

I tried adding db.bolt.auto-compact=false to lnd.conf and trying to launch again but face the same issue.

[guggero]

Ah, sorry, you need to add lnd.db.bolt.auto-compact=false into the lit.conf.

[hex17or]

Thanks, but still I face the same issue.

bitcoin@odroid:~/.lit$ litd
Attempting automatic RPC configuration to bitcoind
Automatically obtained bitcoind's RPC credentials
2021-09-22 13:44:33.855 [INF] LTND: Version: 0.13.0-beta commit=lightning-terminal-v0.5.1-alpha, build=production, logging=default, debuglevel=info
2021-09-22 13:44:33.855 [INF] LTND: Active chain: Bitcoin (network=mainnet)
2021-09-22 13:44:33.876 [INF] RPCS: RPC server listening on 127.0.0.1:10009
2021-09-22 13:44:33.877 [INF] LITD: Dialing lnd gRPC server at 127.0.0.1:10009
----------------------------------------------------------
 Lightning Terminal (LiT) by Lightning Labs

 Operating mode      integrated
 Node status         locked
 Alias               WingDings
 Version             0.13.0-beta
 Web interface       0.0.0.0:8443 (open https://localhost:8443 in your browser)
----------------------------------------------------------
2021-09-22 13:44:33.887 [INF] RPCS: gRPC proxy started at 127.0.0.1:8080
2021-09-22 13:44:33.887 [INF] LTND: Opening the main database, this might take a few minutes...
2021-09-22 13:44:33.887 [INF] LTND: Opening bbolt database, sync_freelist=true, auto_compact=false
2021-09-22 13:44:33.966 [INF] LITD: Listening for http_tls on: [::]:8443
2021-09-22 13:44:34.088 [INF] LNDC: Creating lnd connection to 127.0.0.1:10009
2021-09-22 13:44:34.088 [INF] LNDC: Connected to lnd
2021-09-22 13:44:34.089 [INF] LNDC: Waiting for lnd to unlock
2021-09-22 13:44:34.111 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:44:39.114 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:44:44.119 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:44:49.120 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:44:54.122 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:44:59.126 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:04.131 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:09.136 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:14.138 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:19.142 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:24.145 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:29.149 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:34.160 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:39.165 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:44.170 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:49.174 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:54.178 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:45:59.182 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:46:04.186 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:46:09.190 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:46:14.195 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:46:19.200 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:46:24.205 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:46:29.206 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:46:34.211 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:46:39.216 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:46:44.220 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 13:46:49.225 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
^C2021-09-22 13:46:53.421 [INF] SGNL: Received interrupt
2021-09-22 13:46:53.421 [INF] SGNL: Shutting down...
2021-09-22 13:46:53.422 [INF] SGNL: Gracefully shutting down.
2021-09-22 13:46:53.422 [ERR] LITD: Could not start subservers: context canceled
^C

[guggero]

Are you manually stopping LiT? It looks like lnd is still opening the database. Can you just give it more time to do that? How big is your channel.db file?

[hex17or]

Thank you again! I guess I was being impatient. After waiting for some time, I was able to unlock my wallet successfully.

2021-09-22 17:40:33.627 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 17:40:38.632 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 17:40:43.637 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 17:40:48.638 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 17:40:53.643 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 17:40:58.645 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 17:41:03.646 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: waiting to start, RPC services not available
2021-09-22 17:41:04.331 [INF] CHDB: Checking for schema update: latest_version=22, db_version=22
2021-09-22 17:41:04.331 [INF] LTND: Database now open (time_to_open=4m26.111372635s)!
2021-09-22 17:41:04.331 [INF] LTND: Waiting for wallet encryption password. Use `lncli create` to create a wallet, `lncli unlock` to unlock an existing wallet, or `lncli changepassword` to change the password of an existing wallet and unlock it.
2021-09-22 17:41:08.650 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: wallet locked, unlock it to enable full RPC access
2021-09-22 17:41:13.654 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: wallet locked, unlock it to enable full RPC access
2021-09-22 17:41:18.659 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: wallet locked, unlock it to enable full RPC access

....

2021-09-22 18:00:29.665 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: wallet locked, unlock it to enable full RPC access
2021-09-22 18:00:34.668 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: wallet locked, unlock it to enable full RPC access
2021-09-22 18:00:39.671 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: wallet locked, unlock it to enable full RPC access
2021-09-22 18:00:39.932 [INF] LNWL: Opened wallet
2021-09-22 18:00:40.223 [INF] CHRE: Primary chain is set to: bitcoin
2021-09-22 18:00:40.380 [INF] CHRE: Initializing bitcoind backed fee estimator in CONSERVATIVE mode
2021-09-22 18:00:40.380 [INF] LNWL: Started listening for bitcoind transaction notifications via ZMQ on 127.0.0.1:28333
2021-09-22 18:00:40.380 [INF] LNWL: Started listening for bitcoind block notifications via ZMQ on 127.0.0.1:28332
2021-09-22 18:00:42.884 [INF] LNWL: The wallet has been unlocked without a time limit
2021-09-22 18:00:42.890 [INF] CHRE: LightningWallet opened
2021-09-22 18:00:42.954 [INF] SRVR: Proxying all network traffic via Tor (stream_isolation=true)! NOTE: Ensure the backend node is proxying over Tor as well
2021-09-22 18:00:43.001 [INF] HSWC: Restoring in-memory circuit state from disk
2021-09-22 18:00:43.046 [INF] HSWC: Payment circuits loaded: num_pending=0, num_open=0
2021-09-22 18:00:43.048 [INF] HSWC: Trimming open circuits for chan_id=669857:968:1, start_htlc_id=0
2021-09-22 18:00:43.337 [INF] LTND: Channel backup proxy channel notifier starting
2021-09-22 18:00:43.337 [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
2021-09-22 18:00:43.342 [INF] LTND: Waiting for chain backend to finish sync, start_height=701715
2021-09-22 18:00:44.009 [INF] LNWL: Started rescan from block 00000000000000000001b17317d992bac52a655f3b7b40714898f3c31954c528 (height 701120) for 6 addresses
2021-09-22 18:00:44.694 [INF] LNDC: lnd version: v0.13.0-beta, build tags 'litd,autopilotrpc,signrpc,walletrpc,chainrpc,invoicesrpc,watchtowerrpc'
2021-09-22 18:00:44.706 [INF] LNDC: Using network mainnet
2021-09-22 18:00:44.706 [INF] LNDC: Waiting for lnd to be fully synced to its chain backend, this might take a while

[guggero]

If your DB takes that long to open, then compacting would be a good idea. That potentially takes even longer the first time, so make sure you don't interrupt it. Then the next startup should be faster.