xud doesn't refresh "lnd is WaitingUnlock" state

[kilrau]

How it is

Docker-setup: All testnet clients ready & synced:
t0: restart lndltc, unlock lndltc via lncli unlock
t1: now lndltc works and shows "synced_to_chain": true. But xucli getinfo shows lndtlc "error": "lnd is WaitingUnlock",which is not true ([lncli] Wallet is already unlocked)
t2: restarted xud container - fixed.

How it should be

xud pulls unlock state in 5s interval, same as other states from lnd to automatically detect when it was unlocked successfully.

TODO

• fix xud pulling unlock state in 5s interval, same as other states from lnd to automatically detect when it was unlocked successfully

[sangaman]

This is a really bizarre issue. I can reproduce it locally reliably. Starting off with lnd locked and then unlocking lnd is fine. But following the steps here, where you first start with lnd unlocked, then stop it, then start it again while locked, then unlock it, results in the status within xud getting stuck on locked.

The bizarre part is that the moment I enter a breakpoint in VS code, the error goes away, even if I never hit the break point. On the very next connection attempt, it will properly show that lnd is no longer locked. I can put in log statements that show that it thinks the GetInfo lnd call is still unimplemented, even when it's not. I ensured that I'm properly closing the grpc client between attempts (that was the solution to a similar issue from earlier). This might be a bug with the node grpc implementation, so I may open an issue there.

[kilrau]

As discussed, please open an issue in node grpc. @sangaman

We can track the status in here.

[sangaman]

Issue is open here: grpc/grpc-node#993

[sangaman]

It looks like this may be fixed when using a heartbeat to detect when lnd has gone offline - it could also be related to using newer versions of lnd. I'll open a PR that closes this issue - the issue no longer occurs for me when I try to reproduce it in that PR.

[ghost]

I'm still experiencing similar issue with latest changes with a fresh docker environment during the 2nd start of the environment.

mainnet > getinfo -j
{
  "version": "1.0.0-testnet.1-c559965-dirty",
  ...
  "lndMap": [
    [  
      "BTC",
      {                  
        "status": "lnd is WaitingUnlock",
        ...
      }
    ],
    [  
      "LTC",
      {
        "status": "lnd is WaitingUnlock",
        ...
      }
    ]
  ],
  ...
}

xud seems to be stuck in a loop of trying to verify lnd connections

logs -f xud
xud_1        | 03/10/2019 09:29:42.644 [LND-LTC] info: wallet unlocked
xud_1        | 03/10/2019 09:29:42.669 [LND-BTC] info: wallet unlocked
xud_1        | 03/10/2019 09:29:42.671 [RPC] info: gRPC server completed shutdown
xud_1        | 03/10/2019 09:29:42.697 [P2P] info: Connecting to mainnet XU network
...
xud_1        | 03/10/2019 09:41:02.636 [LND-BTC] info: trying to verify connection to lnd at lndbtc:10009
xud_1        | 03/10/2019 09:41:02.637 [LND-LTC] info: trying to verify connection to lnd at lndltc:10009

After about ~20 minutes the xucli getinfo reported lnds as active.

[sangaman]

xud keeps printing those "trying to verify connection" messages? And just to be clear, you observed this after starting xud while lnds were in a locked state, and then performing the unlock command?

[ghost]

xud keeps printing those "trying to verify connection" messages? And just to be clear, you observed this after starting xud while lnds were in a locked state, and then performing the unlock command?

Yes, this can be reproduced with a fresh testnet/mainnet docker environment.

After the first launch execute down and then start the environment again with bash xud.sh -> xucli unlock.

[sangaman]

Thanks I will look into it.

[sangaman]

I can't reproduce running in my dev environment against a local lnd instanc. @karl will share full logs if this comes up again, which hopefully will shed some light on how lnd went from connected status (which is required for the unlock calls to work) to disconnected.

[kilrau]

I can't reproduce running in my dev environment against a local lnd instanc

It's easily reproduced by running xud-docker @sangaman

[kilrau]

Could you reproduce @sangaman ? If not, I can demonstrate it on my machine.

[kilrau]

Also experienced by @belboo :

LND dropped dead (possibly due to me trying out the whole dictionary of commands on it :slight_smile: ). After docker restart the lndbtc-cli responded ok, allowing me to unlock the LND wallet. xucli, on both status request and getinfo was saying that the LND was still locked.

[kilrau]

I tested several combinations this morning and can't reproduce this. Is your issue still on? @erkarl

[kilrau]

Otherwise, let's close.

[belboo]

Never had the issue since on our side!

[kilrau]

Thanks @belboo ! Closing for now.