Closed lukeroberts closed 3 years ago
guggero
commented
3 years ago Hmm, weird. Trying to reproduce this now. Do you see any errors in lnd that match up time wise? If you run poold from a terminal directly, do you see an additional line that prints the error that caused the shutdown? I think this last line unfortunately is only printed to stdout and not appended to the log.
Also could you perhaps DM me the account key so I can see if I find anything on the server side?
lukeroberts
commented
3 years ago Ah yea here's the output straight from the terminal:
2021-05-31 08:13:42.220 [INF] POOL: Version: 0.5.0-alpha commit=v0.5.0-alpha
2021-05-31 08:13:42.221 [INF] LNDC: Creating lnd connection to localhost:10009
2021-05-31 08:13:42.232 [INF] LNDC: Connected to lnd
2021-05-31 08:13:42.232 [INF] LNDC: Waiting for lnd to unlock
2021-05-31 08:13:42.279 [INF] LNDC: lnd version: v0.12.1-beta, build tags 'autopilotrpc,signrpc,walletrpc,chainrpc,invoicesrpc,watchtowerrpc'
2021-05-31 08:13:42.280 [INF] LNDC: Using network mainnet
2021-05-31 08:13:42.287 [INF] LNDC: Waiting for lnd to be fully synced to its chain backend, this might take a while
2021-05-31 08:13:42.318 [INF] LNDC: lnd is now fully synced to its chain backend
2021-05-31 08:13:42.382 [INF] POOL: Auction server address: pool.lightning.finance:12010
2021-05-31 08:13:42.382 [INF] CLDB: Checking for schema update: latest_version=1, db_version=1
2021-05-31 08:13:42.392 [INF] RPCS: Starting trader server
2021-05-31 08:13:42.425 [INF] RPCS: Connected to lnd node <<>> with pubkey <<>>
2021-05-31 08:13:42.427 [INF] ACCT: Watching spend of <<>>:0 for account <<>>
2021-05-31 08:13:42.905 [DBG] AUCT: Connected successfully to server after 1 tries
2021-05-31 08:13:42.905 [INF] AUCT: Successfully connected to auction server
2021-05-31 08:13:42.992 [TRC] AUCT: Received msg=&auctioneerrpc.ServerAuctionMessage{Msg:(*auctioneerrpc.ServerAuctionMessage_Challenge)(0xc000006178), XXX_NoUnkeyedLiteral:struct {}{}, XXX_unrecognized:[]uint8(nil), XXX_sizecache:0}, err=<nil> from server
2021-05-31 08:13:42.993 [DBG] LNDC: Closing lnd connection
2021-05-31 08:13:43.001 [DBG] LNDC: Wait for client to finish
2021-05-31 08:13:43.004 [DBG] LNDC: Wait for chain notifier to finish
2021-05-31 08:13:43.001 [ERR] ACCT: Unable to receive block notification: rpc error: code = Canceled desc = grpc: the client connection is closing
2021-05-31 08:13:43.005 [DBG] LNDC: Wait for invoices to finish
2021-05-31 08:13:43.007 [DBG] LNDC: Lnd services finished
2021-05-31 08:13:43.007 [DBG] LNDC: Lnd services finished
2021-05-31 08:13:43.008 [INF] AUCT: Shutting down auctioneer client
2021-05-31 08:13:43.011 [DBG] AUCT: Closing server stream
2021-05-31 08:13:43.012 [TRC] AUCT: Received msg=(*auctioneerrpc.ServerAuctionMessage)(nil), err=rpc error: code = Canceled desc = context canceled from server
unable to start server: unable to start account manager: unable to resume account <<>>: unable to subscribe for account updates: rpc error: code = Unknown desc = permission deniedAnd here's the output from lnd at the time:
2021-05-31 08:13:42.426 [INF] NTFN: New block epoch subscription
2021-05-31 08:13:42.429 [INF] NTFN: New block epoch subscription
2021-05-31 08:13:42.434 [INF] NTFN: New spend subscription: spend_id=64, outpoint=<<>>:0, script=0 <<>>, height_hint=<<>>
2021-05-31 08:13:43.002 [INF] NTFN: Cancelling epoch notification, epoch_id=58
2021-05-31 08:13:43.005 [INF] NTFN: Cancelling epoch notification, epoch_id=57
2021-05-31 08:13:43.002 [INF] NTFN: Canceling spend notification: spend_id=64, outpoint=<<>>:0, script=0 <<>>
2021-05-31 08:13:43.005 [ERR] RPCS: [/chainrpc.ChainNotifier/RegisterBlockEpochNtfn]: context canceled
2021-05-31 08:13:43.005 [ERR] RPCS: [/chainrpc.ChainNotifier/RegisterBlockEpochNtfn]: context canceled
2021-05-31 08:13:43.005 [ERR] RPCS: [/chainrpc.ChainNotifier/RegisterSpendNtfn]: context canceledWorked with @guggero on the side; this turned out to be an issue with lnd's current .macaroon files for my instance. After removing all of my .macaroon files, restarting lnd, and unlocking lnd wallet those were recreated and pool v0.5.0 was then able to work
Expected behavior
Service starts successfully connecting to auction server after upgrading to version v0.5.0 from v0.4.1
Actual behavior
Service exits right after startup after upgrading to v0.5.0
To reproduce
Error occurs immediately after starting poold. When I downgrade back to v0.4.1 everything works as expected
System information
lnd v0.12.1 and poold v0.5.0 are both running on the same machine as standalone binaries on Windows Server 2019. I currently have an account open with asks active