mynodebtc/mynode

Lightning Network Error. Will Not Connect

RowdyMuncher opened this issue · 5 comments

Lightning will not connect.

Setup: Raspberry Pi 5 8GB
Runing TP_Link Omada Setup.
Node on its own VLAN
I can manually port forward but cant find a solution for NATPMP even after talking to Tech support.

Bitcoin Running
Both Bitcoin and Lightning have TOR enabled. I have tried unselecting TOR makes no difference.

I know by looking at the logs that the issue is with NATPMP. Lightning just goes round in a loop. Logs below. Help required.
Thanks.

Jan 12 14:57:22 mynode lnd[15876]: Not shutting down!
Jan 12 14:57:22 mynode lnd[15876]: Checking if device is shutting down...
Jan 12 14:57:22 mynode systemd[1]: Starting lnd.service - LND Lightning Daemon...
Jan 12 14:57:22 mynode systemd[1]: lnd.service: Consumed 3.346s CPU time.
Jan 12 14:57:22 mynode systemd[1]: Stopped lnd.service - LND Lightning Daemon.
Jan 12 14:57:22 mynode systemd[1]: lnd.service: Scheduled restart job, restart counter is at 51.
Jan 12 14:57:21 mynode systemd[1]: lnd.service: Consumed 3.346s CPU time.
Jan 12 14:57:21 mynode systemd[1]: lnd.service: Failed with result 'exit-code'.
Jan 12 14:57:21 mynode systemd[1]: lnd.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 14:57:21 mynode lnd[15786]: unable to create server: unable to discover a NAT-PMP enabled device on the local network: read udp 192.168.20.90:56150->192.168.20.1:5351: recvfrom: connection refused
Jan 12 14:57:21 mynode lnd[15786]: 2024-01-12 14:57:21.184 [INF] LTND: Shutdown complete
Jan 12 14:57:21 mynode lnd[15786]: 2024-01-12 14:57:21.183 [ERR] LTND: error stopping tor controller: invalid arguments: unexpected code
Jan 12 14:57:21 mynode lnd[15786]: 2024-01-12 14:57:21.182 [ERR] TORC: DEL_ONION got error: invalid arguments: unexpected code
Jan 12 14:57:21 mynode lnd[15786]: 2024-01-12 14:57:21.182 [INF] TORC: Stopping tor controller
Jan 12 14:57:21 mynode lnd[15786]: 2024-01-12 14:57:21.182 [ERR] LTND: Shutting down because error in main method: unable to create server: unable to discover a NAT-PMP enabled device on the local network: read udp 192.168.20.90:56150->192.168.20.1:5351: recvfrom: connection refused
Jan 12 14:57:21 mynode lnd[15786]: 2024-01-12 14:57:21.182 [ERR] SRVR: unable to discover a NAT-PMP enabled device on the local network: read udp 192.168.20.90:56150->192.168.20.1:5351: recvfrom: connection refused
Jan 12 14:57:21 mynode lnd[15786]: 2024-01-12 14:57:21.178 [INF] SRVR: Scanning local network for a NAT-PMP enabled device
Jan 12 14:57:21 mynode lnd[15786]: 2024-01-12 14:57:21.178 [ERR] SRVR: Unable to discover a UPnP enabled device on the local network: context canceled
Jan 12 14:57:18 mynode systemd[1]: Started lnd.service - LND Lightning Daemon.
Jan 12 14:57:13 mynode lnd[15786]: 2024-01-12 14:57:13.126 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: the RPC server is in the process of starting up, but not yet ready to accept calls
Jan 12 14:57:12 mynode lnd[15786]: 2024-01-12 14:57:12.182 [INF] LNWL: Finished rescan for 1 address (synced to block 000000000000000000036a83de21aa03b9c1da5e1e4f053c193a5677a811b816, height 825522)
Jan 12 14:57:12 mynode lnd[15786]: 2024-01-12 14:57:12.182 [INF] LNWL: Done catching up block hashes
Jan 12 14:57:12 mynode lnd[15786]: 2024-01-12 14:57:12.180 [INF] LNWL: Catching up block hashes to height 825522, this might take a while
Jan 12 14:57:12 mynode lnd[15786]: 2024-01-12 14:57:12.178 [INF] LNWL: Started rescan from block 000000000000000000036a83de21aa03b9c1da5e1e4f053c193a5677a811b816 (height 825522) for 1 address
Jan 12 14:57:11 mynode lnd[15786]: 2024-01-12 14:57:11.178 [INF] SRVR: Scanning local network for a UPnP enabled device
Jan 12 14:57:11 mynode lnd[15786]: 2024-01-12 14:57:11.178 [INF] HSWC: Payment circuits loaded: num_pending=0, num_open=0
Jan 12 14:57:11 mynode lnd[15786]: 2024-01-12 14:57:11.177 [INF] HSWC: Restoring in-memory circuit state from disk
Jan 12 14:57:11 mynode lnd[15786]: 2024-01-12 14:57:11.177 [INF] HSWC: Finished cleaning: no closed channels found, no actions taken.
Jan 12 14:57:11 mynode lnd[15786]: 2024-01-12 14:57:11.177 [INF] HSWC: Cleaning circuits from disk for closed channels
Jan 12 14:57:11 mynode lnd[15786]: 2024-01-12 14:57:11.172 [INF] TORC: Starting tor controller
Jan 12 14:57:11 mynode lnd[15786]: 2024-01-12 14:57:11.172 [INF] SRVR: Onion services are accessible via Tor! NOTE: Traffic to clearnet services is not routed via Tor.
Jan 12 14:57:11 mynode lnd[15786]: 2024-01-12 14:57:11.164 [INF] CHRE: LightningWallet opened
Jan 12 14:57:11 mynode lnd[15786]: 2024-01-12 14:57:11.161 [INF] LNWL: The wallet has been unlocked without a time limit
Jan 12 14:57:09 mynode lnd[15786]: 2024-01-12 14:57:09.974 [INF] LNWL: Started listening for bitcoind transaction notifications via ZMQ on 127.0.0.1:28333
Jan 12 14:57:09 mynode lnd[15786]: 2024-01-12 14:57:09.974 [INF] LNWL: Started listening for bitcoind block notifications via ZMQ on 127.0.0.1:28332
Jan 12 14:57:09 mynode lnd[15786]: 2024-01-12 14:57:09.974 [INF] CHRE: Initializing bitcoind backed fee estimator in CONSERVATIVE mode
Jan 12 14:57:09 mynode lnd[15786]: 2024-01-12 14:57:09.958 [INF] CHRE: Primary chain is set to: bitcoin
Jan 12 14:57:09 mynode lnd[15786]: 2024-01-12 14:57:09.869 [INF] LNWL: Opened wallet
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.782 [INF] LTND: Attempting automatic wallet unlock with password provided in file
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.782 [INF] LTND: Database(s) now open (time_to_open=374.464157ms)!
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.782 [INF] CHDB: Checking for optional update: prune_revocation_log=false, db_version=empty
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.782 [INF] CHDB: Checking for schema update: latest_version=31, db_version=31
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.431 [INF] LTND: Creating local graph and channel state DB instances
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.431 [INF] CHDB: Not compacting database file at /home/bitcoin/.lnd/data/graph/mainnet/sphinxreplay.db, it was last compacted at 2024-01-11 13:13:56.198474771 -0600 CST (25h43m12s ago), min age is set to 168h0m0s
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.431 [INF] CHDB: Not compacting database file at /home/bitcoin/.lnd/data/chain/bitcoin/mainnet/macaroons.db, it was last compacted at 2024-01-11 13:13:56.191497699 -0600 CST (25h43m12s ago), min age is set to 168h0m0s
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.408 [INF] CHDB: Not compacting database file at /home/bitcoin/.lnd/data/graph/mainnet/channel.db, it was last compacted at 2024-01-11 13:13:56.183948611 -0600 CST (25h43m12s ago), min age is set to 168h0m0s
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.408 [INF] LTND: Opening bbolt database, sync_freelist=false, auto_compact=true
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.408 [INF] LTND: Opening the main database, this might take a few minutes...
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.408 [INF] RPCS: gRPC proxy started at 0.0.0.0:10080
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.400 [INF] RPCS: RPC server listening on 0.0.0.0:10009
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.399 [INF] LTND: Active chain: Bitcoin (network=mainnet)
Jan 12 14:57:08 mynode lnd[15786]: 2024-01-12 14:57:08.399 [INF] LTND: Version: 0.17.2-beta commit=v0.17.2-beta, build=production, logging=default, debuglevel=info
Jan 12 14:57:08 mynode lnd[15786]: Automatically obtained bitcoind's RPC credentials
Jan 12 14:57:08 mynode lnd[15786]: Attempting automatic RPC configuration to bitcoind
Jan 12 14:57:08 mynode lnd[15775]: + exit 0
Jan 12 14:57:08 mynode lnd[15776]: }
Jan 12 14:57:08 mynode lnd[15776]: "warnings": ""
Jan 12 14:57:08 mynode lnd[15776]: "pruned": false,
Jan 12 14:57:08 mynode lnd[15776]: "size_on_disk": 614032635515,
Jan 12 14:57:08 mynode lnd[15776]: "chainwork": "0000000000000000000000000000000000000000654e6cd49d58637d274f18bb",
Jan 12 14:57:08 mynode lnd[15776]: "initialblockdownload": false,
Jan 12 14:57:08 mynode lnd[15776]: "verificationprogress": 0.9999953494757905,
Jan 12 14:57:08 mynode lnd[15776]: "mediantime": 1705088604,
Jan 12 14:57:08 mynode lnd[15776]: "time": 1705092227,
Jan 12 14:57:08 mynode lnd[15776]: "difficulty": 73197634206448.34,
Jan 12 14:57:08 mynode lnd[15776]: "bestblockhash": "000000000000000000036a83de21aa03b9c1da5e1e4f053c193a5677a811b816",
Jan 12 14:57:08 mynode lnd[15776]: "headers": 825522,
Jan 12 14:57:08 mynode lnd[15776]: "blocks": 825522,
Jan 12 14:57:08 mynode lnd[15776]: "chain": "main",
Jan 12 14:57:08 mynode lnd[15776]: {
Jan 12 14:57:08 mynode lnd[15775]: + bitcoin-cli -datadir=/mnt/hdd/mynode/bitcoin -rpcwait getblockchaininfo
Jan 12 14:57:08 mynode lnd[15775]: + '[' '!' -f /mnt/hdd/mynode/.mynode_bitcoin_synced ']'
Jan 12 14:57:08 mynode lnd[15775]: Checking if Bitcoin is synced...
Jan 12 14:57:08 mynode lnd[15775]: + echo 'Checking if Bitcoin is synced...'
Jan 12 14:57:08 mynode lnd[15775]: + set -e
Jan 12 14:57:08 mynode lnd[15772]: Not shutting down!
Jan 12 14:57:08 mynode lnd[15772]: Checking if device is shutting down...
Jan 12 14:57:08 mynode systemd[1]: Starting lnd.service - LND Lightning Daemon...
Jan 12 14:57:08 mynode systemd[1]: lnd.service: Consumed 3.188s CPU time, read 768.0K from disk, written 0B to disk.
Jan 12 14:57:08 mynode systemd[1]: Stopped lnd.service - LND Lightning Daemon.
Jan 12 14:57:08 mynode systemd[1]: lnd.service: Scheduled restart job, restart counter is at 50.
Jan 12 14:57:07 mynode systemd[1]: lnd.service: Consumed 3.188s CPU time, read 768.0K from disk, written 0B to disk.
Jan 12 14:57:07 mynode systemd[1]: lnd.service: Failed with result 'exit-code'.
Jan 12 14:57:07 mynode systemd[1]: lnd.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 14:57:07 mynode lnd[15669]: unable to create server: unable to discover a NAT-PMP enabled device on the local network: read udp 192.168.20.90:55091->192.168.20.1:5351: recvfrom: connection refused
Jan 12 14:57:07 mynode lnd[15669]: 2024-01-12 14:57:07.077 [INF] LTND: Shutdown complete
Jan 12 14:57:07 mynode lnd[15669]: 2024-01-12 14:57:07.075 [ERR] LTND: error stopping tor controller: invalid arguments: unexpected code
Jan 12 14:57:07 mynode lnd[15669]: 2024-01-12 14:57:07.075 [ERR] TORC: DEL_ONION got error: invalid arguments: unexpected code
Jan 12 14:57:07 mynode lnd[15669]: 2024-01-12 14:57:07.075 [INF] TORC: Stopping tor controller
Jan 12 14:57:07 mynode lnd[15669]: 2024-01-12 14:57:07.075 [ERR] LTND: Shutting down because error in main method: unable to create server: unable to discover a NAT-PMP enabled device on the local network: read udp 192.168.20.90:55091->192.168.20.1:5351: recvfrom: connection refused
Jan 12 14:57:07 mynode lnd[15669]: 2024-01-12 14:57:07.075 [ERR] SRVR: unable to discover a NAT-PMP enabled device on the local network: read udp 192.168.20.90:55091->192.168.20.1:5351: recvfrom: connection refused
Jan 12 14:57:07 mynode lnd[15669]: 2024-01-12 14:57:07.053 [INF] SRVR: Scanning local network for a NAT-PMP enabled device
Jan 12 14:57:07 mynode lnd[15669]: 2024-01-12 14:57:07.053 [ERR] SRVR: Unable to discover a UPnP enabled device on the local network: context canceled
Jan 12 14:57:05 mynode lnd[15669]: 2024-01-12 14:57:05.077 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: the RPC server is in the process of starting up, but not yet ready to accept calls
Jan 12 14:57:04 mynode systemd[1]: Started lnd.service - LND Lightning Daemon.

If you was to use NAT, you can customize the LND config to work with manual port forwarding and get it setup with your network. If you log a support ticket, we can help with some options to avoid the network issue or get your running on another network like tor.

Thanks you for your reply. As I have just started with mynode I'm not sure where to log a ticket from. Within the app or website? Can you let me know and I'll log a support ticket. Cheers

You can log a ticket here (you'll need an account).

https://www.mynodebtc.com/support_tickets/tickets

Your error is:

Jan 12 14:57:07 mynode lnd[15669]: 2024-01-12 14:57:07.075 [ERR] LTND: Shutting down because error in main method: unable to create server: unable to discover a NAT-PMP enabled device on the local network: read udp 192.168.20.90:55091->192.168.20.1:5351: recvfrom: connection refused

Add following line in LND config:
nat=false

Add following line in LND config: nat=false

Thank you this worked! I was having the same issue, as nat=true is in the default config