search

lightningnetwork / lnd

Lightning Network Daemon ⚡️
MIT License
7.67k stars 2.07k forks source link

Pending waiting_close_channels with channel state ChanStatusRestored #5593

Closed clockshell closed 3 years ago

clockshell commented 3 years ago

Background

About 9 months ago now, I moved and my node was offline for some weeks. When I set it up agian, ACINQ has closed the channel to my node and it is still in the state pending closing channels, I did not get any refunds.

Your environment

Steps to reproduce

    "waiting_close_channels": [
        {
            "channel": {
                "remote_node_pub": "03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f",
                "channel_point": "aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1",
                "capacity": "403645",
                "local_balance": "0",
                "remote_balance": "0",
                "local_chan_reserve_sat": "0",
                "remote_chan_reserve_sat": "0",
                "initiator": "INITIATOR_LOCAL",
                "commitment_type": "LEGACY"
            },
            "limbo_balance": "0",
            "commitments": {
                "local_txid": "",
                "remote_txid": "",
                "remote_pending_txid": "",
                "local_commit_fee_sat": "0",
                "remote_commit_fee_sat": "0",
                "remote_pending_commit_fee_sat": "0"
            }
        }
    ]

I tried 

lncli closechannel aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443 1

with the following result:

[lncli] rpc error: code = Unknown desc = cannot close channel with state: ChanStatusRestored

same with --force option.

Expected behaviour

Channel funds go back to my on-chain balance

Actual behaviour

It does not. I talked to ACINQ and from their side they confirmed that my node has not picked up the closing channel confirmation, so how can I get it to do so?

Best regards, I hope somebody here can help me, please let me know, if you need any further information,

clockshell

guggero commented 3 years ago

Can you grep your log with aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443 and 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f to see what's happening? Since this is a LEGACY type channel, your node needs a secret from the remote node to re-claim the funds. My suspicion is that it doesn't get it from the Acinq node for some reason.

clockshell commented 3 years ago 
root@raspberrypi:/home/admin# grep aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443 /mnt/hdd/lnd/logs/bitcoin/mainnet/lnd.log
2021-08-02 12:17:40.151 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): new block (height=693838) examining active HTLC's
2021-08-02 12:17:40.151 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): checking commit chain actions at height=693838, in_htlc_count=0, out_htlc_count=0
root@raspberrypi:/home/admin# grep 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f /mnt/hdd/lnd/logs/bitcoin/mainnet/lnd.log
2021-08-02 12:16:51.877 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:16:51.877 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:17:21.701 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:17:22.124 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:17:52.168 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:17:52.170 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:18:21.701 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:18:21.914 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:18:51.907 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:18:51.907 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:19:21.701 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:19:21.973 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:19:56.888 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:19:56.889 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:19:56.889 [DBG] PEER: Received ChannelAnnouncement(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=762877451401101312) from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:20:21.702 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:20:22.035 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:20:51.985 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:20:51.985 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:21:21.702 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 12:21:21.936 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735

This is all I have right now since I did unfortunately not make any backups of the log files back then.

guggero commented 3 years ago

Can you restart your node and grep again? When the channel is booted up it should ask Acinq for the info.

clockshell commented 3 years ago

Right after restart:

root@raspberrypi:/home/admin# grep aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443 /mnt/hdd/lnd/logs/bitcoin/mainnet/lnd.log
2021-08-02 14:39:37.116 [DBG] CHBU: Crafting backup for ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1)
2021-08-02 14:39:55.949 [DBG] CNCT: New ChainEventSubscription(id=0) for ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1)
2021-08-02 14:39:55.959 [DBG] CNCT: Starting chain watcher for ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1)
2021-08-02 14:39:55.962 [DBG] NTFN: Using height hint 654921 retrieved from cache for outpoint=aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1, script=0 a699d47bb28f29e24f2cddb254b452b4f885438e8591cc0f0d41553a558631e4 instead of 642767
2021-08-02 14:39:55.964 [INF] NTFN: New spend subscription: spend_id=2, outpoint=aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1, script=0 a699d47bb28f29e24f2cddb254b452b4f885438e8591cc0f0d41553a558631e4, height_hint=654921
2021-08-02 14:39:55.964 [INF] NTFN: Dispatching historical spend rescan for outpoint=aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1, script=0 a699d47bb28f29e24f2cddb254b452b4f885438e8591cc0f0d41553a558631e4, start=654921, end=693853
2021-08-02 14:39:57.248 [INF] CNCT: Close observer for ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1) active
2021-08-02 14:39:57.624 [DBG] CNCT: Starting ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1), htlc_set=(map[contractcourt.HtlcSetKey]contractcourt.htlcSet) (len=2) {
2021-08-02 14:39:57.640 [INF] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): starting state=StateDefault, trigger=chainTrigger, triggerHeight=693853
2021-08-02 14:39:57.640 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): new block (height=693853) examining active HTLC's
2021-08-02 14:39:57.640 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): checking commit chain actions at height=693853, in_htlc_count=0, out_htlc_count=0
2021-08-02 14:40:00.308 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): new block (height=693853) examining active HTLC's
2021-08-02 14:40:00.309 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): checking commit chain actions at height=693853, in_htlc_count=0, out_htlc_count=0
2021-08-02 14:48:52.301 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): new block (height=693854) examining active HTLC's
2021-08-02 14:48:52.301 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): checking commit chain actions at height=693854, in_htlc_count=0, out_htlc_count=0
2021-08-02 14:48:52.610 [DBG] LNWL: ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): starting local commitment: (*lnwallet.commitment)(0x400171c480)({
2021-08-02 14:48:52.617 [DBG] LNWL: ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): starting remote commitment: (*lnwallet.commitment)(0x40013ff8c0)({
2021-08-02 14:48:52.618 [DBG] LNWL: ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): Restoring 0 dangling remote updates
2021-08-02 14:48:52.618 [DBG] LNWL: ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): Restoring 0 local updates that the peer should sign
2021-08-02 14:48:52.618 [DBG] FNDG: ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1) with chan_id=43f40ec339ce1b1d030f0f1d8e0991fc28d264e9ab0a3b5670e017e51c6096ab not found in opening database, assuming already announced to the network
2021-08-02 14:48:53.426 [WRN] CHBU: Replacing disk backup for ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1) w/ newer version
2021-08-02 14:48:54.963 [DBG] LNWL: ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): starting local commitment: (*lnwallet.commitment)(0x40001e0180)({
2021-08-02 14:48:54.968 [DBG] LNWL: ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): starting remote commitment: (*lnwallet.commitment)(0x4001206600)({
2021-08-02 14:48:54.968 [DBG] LNWL: ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): Restoring 0 dangling remote updates
2021-08-02 14:48:54.969 [DBG] LNWL: ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): Restoring 0 local updates that the peer should sign
2021-08-02 14:48:54.969 [INF] PEER: NodeKey(03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f) loading ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1)
2021-08-02 14:48:54.969 [WRN] PEER: Unable to find our forwarding policy for channel aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1, using default values
2021-08-02 14:48:54.969 [DBG] CNCT: New ChainEventSubscription(id=1) for ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1)
2021-08-02 14:48:54.971 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1)
2021-08-02 14:50:45.444 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): new block (height=693855) examining active HTLC's
2021-08-02 14:50:45.444 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): checking commit chain actions at height=693855, in_htlc_count=0, out_htlc_count=0
2021-08-02 14:53:47.139 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): new block (height=693856) examining active HTLC's
2021-08-02 14:53:47.139 [DBG] CNCT: ChannelArbitrator(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1): checking commit chain actions at height=693856, in_htlc_count=0, out_htlc_count=0
root@raspberrypi:/home/admin# grep 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f /mnt/hdd/lnd/logs/bitcoin/mainnet/lnd.log
2021-08-02 14:39:36.617 [DBG] CRTR: Reporting pair failure to Mission Control: pair=03fab7f8655169ea77d9691d4bd359e97782cb6177a6f76383994ed9c262af97a5 -> 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f, amt=1002251 mSAT
2021-08-02 14:39:36.617 [DBG] CRTR: Setting 03fab7f8655169ea77d9691d4bd359e97782cb6177a6f76383994ed9c262af97a5->03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f range to [0 mSAT-1002251 mSAT]
2021-08-02 14:39:36.618 [DBG] CRTR: Reporting pair success to Mission Control: pair=02360f8e4f4181892136af6fe302c4017fb1e57672505e8584ae2acac87792deb6 -> 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f, amt=41020 mSAT
2021-08-02 14:39:36.618 [DBG] CRTR: Setting 02360f8e4f4181892136af6fe302c4017fb1e57672505e8584ae2acac87792deb6->03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f range to [41020 mSAT-0 mSAT]
2021-08-02 14:39:36.618 [DBG] CRTR: Reporting pair success to Mission Control: pair=03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f -> 035f209faaea75427949e3e6c1fc9edafbf751f08706506bb873fdc93ffc2d4e2c, amt=40000 mSAT
2021-08-02 14:39:36.618 [DBG] CRTR: Setting 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f->035f209faaea75427949e3e6c1fc9edafbf751f08706506bb873fdc93ffc2d4e2c range to [40000 mSAT-0 mSAT]
2021-08-02 14:48:53.654 [INF] SRVR: Finalizing connection to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@127.0.0.1:49522, inbound=true
2021-08-02 14:48:53.654 [DBG] PRNF: PeerNotifier notifying peer: 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f online
2021-08-02 14:48:53.669 [INF] PEER: Legacy channel open with peer: 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f, downgrading static remote required feature bit to optional
2021-08-02 14:48:53.669 [DBG] PEER: Sending Init to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@127.0.0.1:49522
2021-08-02 14:48:53.670 [INF] PEER: disconnecting 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@127.0.0.1:49522, reason: unable to start peer: unable to send init msg: write tcp 127.0.0.1:9735->127.0.0.1:49522: write: broken pipe
2021-08-02 14:48:53.670 [DBG] SRVR: Peer 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@127.0.0.1:49522 has been disconnected
2021-08-02 14:48:53.670 [DBG] FNDG: Cancelling all reservations for peer 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f
2021-08-02 14:48:53.670 [DBG] FNDG: No active reservations for node: 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f
2021-08-02 14:48:53.670 [DBG] SRVR: Notifying that peer 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@127.0.0.1:49522 is offline
2021-08-02 14:48:53.670 [DBG] SRVR: removing peer 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@127.0.0.1:49522
2021-08-02 14:48:53.671 [DBG] PRNF: PeerNotifier notifying peer: 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f offline
2021-08-02 14:48:53.702 [DBG] SRVR: Attempting persistent connection to channel peer 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:48:53.702 [DBG] SRVR: Attempting persistent connection to channel peer 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@of7husrflx7sforh3fw6yqlpwstee3wg5imvvmkp4bz6rbjxtg5nljad.onion:9735
2021-08-02 14:48:53.703 [DBG] BTCN: Attempting to connect to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735 (reqid 5)
2021-08-02 14:48:53.703 [DBG] BTCN: Attempting to connect to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@of7husrflx7sforh3fw6yqlpwstee3wg5imvvmkp4bz6rbjxtg5nljad.onion:9735 (reqid 6)
2021-08-02 14:48:54.764 [DBG] BTCN: Connected to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735 (reqid 5)
2021-08-02 14:48:54.764 [INF] SRVR: Established connection to: 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:48:54.764 [INF] SRVR: Finalizing connection to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735, inbound=false
2021-08-02 14:48:54.765 [DBG] PRNF: PeerNotifier notifying peer: 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f online
2021-08-02 14:48:54.768 [INF] PEER: Legacy channel open with peer: 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f, downgrading static remote required feature bit to optional
2021-08-02 14:48:54.768 [DBG] PEER: Sending Init to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:48:54.769 [DBG] BTCN: Canceling: 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@of7husrflx7sforh3fw6yqlpwstee3wg5imvvmkp4bz6rbjxtg5nljad.onion:9735 (reqid 6)
2021-08-02 14:48:54.956 [DBG] PEER: Received Init from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:48:54.957 [DBG] PEER: Loaded 2 active channels from database with NodeKey(03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f)
2021-08-02 14:48:54.969 [INF] PEER: NodeKey(03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f) loading ChannelPoint(aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443:1)
2021-08-02 14:48:54.982 [INF] PEER: NodeKey(03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f) loading ChannelPoint(69d56731034902c9e203dcf9b427bae6293ab6b1154f5270f39380fa5eaf0cf4:0)
2021-08-02 14:48:54.983 [INF] PEER: Negotiated chan series queries with 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f
2021-08-02 14:48:54.983 [INF] DISC: Creating new GossipSyncer for peer=03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f
2021-08-02 14:48:54.983 [DBG] SRVR: Notifying that peer 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735 is online
2021-08-02 14:48:54.983 [DBG] DISC: Starting GossipSyncer(03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f)
2021-08-02 14:48:54.983 [DBG] DISC: GossipSyncer(03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f): state=chansSynced, type=PassiveSync
2021-08-02 14:48:54.983 [DBG] PEER: Sending ChannelReestablish(next_local_height=1, remote_tail_height=0) to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:48:54.983 [DBG] PEER: Sending ChannelReestablish(next_local_height=226, remote_tail_height=225) to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:48:54.983 [DBG] PEER: Sending NodeAnnouncement(node=03eea3e2115e1d2c1038e0826f36dabc1b91d019445c07ecfc3a3b0930f285620e, update_time=2021-08-02 14:39:53 +0100 BST) to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:48:55.058 [DBG] PEER: Received ChannelReestablish(next_local_height=226, remote_tail_height=225) from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:48:55.208 [INF] PEER: unable to read message from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735: unable to parse message of unknown type: <unknown>
2021-08-02 14:48:57.277 [DBG] BTCN: Ignoring connection for canceled connreq=03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@of7husrflx7sforh3fw6yqlpwstee3wg5imvvmkp4bz6rbjxtg5nljad.onion:9735 (reqid 6)
2021-08-02 14:49:25.309 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:49:25.309 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:49:54.983 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:49:55.265 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:50:25.282 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:50:25.282 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:50:54.983 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:50:55.461 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:51:25.441 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:51:25.442 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:51:54.983 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:51:55.279 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:52:25.303 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:52:25.303 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:52:54.983 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:52:55.191 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:53:25.210 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:53:25.210 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:53:54.983 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:53:55.228 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:54:25.235 [DBG] PEER: Received Ping from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:54:25.235 [DBG] PEER: Sending Pong to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:54:54.983 [DBG] PEER: Sending Ping to 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
2021-08-02 14:54:55.170 [DBG] PEER: Received Pong from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735
clockshell commented 3 years ago

Should I maybe backup and delete the lnd.log and then restart one more time, to get a fresh one?

guggero commented 3 years ago 
PEER: unable to read message from 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f@34.239.230.56:9735: unable to parse message of unknown type: <unknown>

Sounds like Acinq is sending a weird message back for your node's ChannelReestablish message... Might be worth opening an issue in their repo. If they can get the last commit point from their DB you can use chantools rescueclosed --force_close_addr bc1q9j9zpxtzywv8ly98s7s5s853nqtuxm4ym40pex --commit_point <channel_point_from_acinq> to get the private key for your funds.

clockshell commented 3 years ago

Thanks alot, I will report back!

Edit: Where do you get the bc1q9j9zpxtzywv8ly98s7s5s853nqtuxm4ym40pex address from? And do I have to change it to one of mine?

pm47 commented 3 years ago

Acinq is sending a weird message back for your node's ChannelReestablish message

We are using the new warning messages (https://github.com/lightningnetwork/lightning-rfc/pull/834), I believe lnd doesn't yet interpret those.

If they can get the last commit point from their DB

The commitment point for the published transaction was 02d04103b4cdcfb84e975947c35b03b0828f99b4e78473845fd7969b979c933e02.

When I set it up agian, ACINQ has closed the channel to my node and it is still in the state pending closing channels, I did not get any refunds.

The commitment tx is https://mempool.space/fr/tx/4f4092e7d14f1ce5ff9d85de0a6409d3c73728802209af28bbe2ba25b8f4efb9. the user's output was for 0.00372168 BTC, it has been spent already, so AFAICT your node did claim the funds.

Also, we did not close unilaterally, @clockshell's node requested us to force close with a unable to resume channel, recovery required message.

clockshell commented 3 years ago

I did find the private key now. Can you help me proceed? The channel though is still listed in pending_close_channels.

guggero commented 3 years ago

Where do you get the bc1q9j9zpxtzywv8ly98s7s5s853nqtuxm4ym40pex address from?

That's what you see if you follow the channel funding TX on a block explorer.

it has been spent already, so AFAICT your node did claim the funds.

Oh, I didn't even check that, I assumed it would still unclaimed. Sorry about that! So @clockshell your node reclaimed the funds a long time ago (November 2020), they went into this channel open: https://1ml.com/channel/720096553332768769.

You can use lncli abandonchannel to get rid of the channel.

note added: abandonchannel is a dangerous command and can lead to loss of funds if used incorrectly - ask in the LND slack channel if unsure

I'll open a new issue for the warning messages that we need to implement. That's AFAICT the only reason why the channel hasn't been fully resolved by lnd.

guggero commented 3 years ago

By the way, thank you @pm47 for the fast response and all the additional information!

clockshell commented 3 years ago

$ lncli abandonchannel aa96601ce517e070563b0aabe964d228fc91098e1d0f0f031d1bce39c30ef443 [lncli] rpc error: code = Unknown desc = AbandonChannel RPC call only available in dev builds

Seems like I need a dev build?

guggero commented 3 years ago

If you're on lnd v0.13.1-beta there's a special --i_know_what_im_doing flag, see lncli abandonchannel --help.

clockshell commented 3 years ago

$ lnd --version lnd version 0.13.0-beta commit=v0.13.0-beta

I got the update from https://www.lightningnode.info/technicals/lnd.updates I guess I will have to wait it out.

Thank you for your help!

guggero commented 3 years ago

Hmm, maybe it was added in 0.13.0. check --help to make sure.

clockshell commented 3 years ago

note added: abandonchannel is a dangerous command and can lead to loss of funds if used incorrectly - ask in the LND slack channel if unsure

`$ lncli abandonchannel --help NAME: lncli abandonchannel - Abandons an existing channel.

USAGE: lncli abandonchannel [command options] funding_txid [output_index]

CATEGORY: Channels

DESCRIPTION:

Removes all channel state from the database except for a close summary. This method can be used to get rid of permanently unusable channels due to bugs fixed in newer versions of lnd.

Only available when lnd is built in debug mode.

To view which funding_txids/output_indexes can be used for this command, see the channel_point values within the listchannels command output. The format for a channel_point is 'funding_txid:output_index'.

OPTIONS: --funding_txid value the txid of the channel's funding transaction --output_index value the output index for the funding output of the funding transaction (default: 0)`

Nope, looks like it is added in 0.13.1

Roasbeef commented 3 years ago

We are using the new warning messages (lightningnetwork/lightning-rfc#834), I believe lnd doesn't yet interpret those.

@pm47 shouldn't that be always gated by us advertising a new feature bit to signal that we actually understand the message? Otherwise, we only act/log on the current error message. Still need catch up with the spec on my end...

pm47 commented 3 years ago

@pm47 shouldn't that be always gated by us advertising a new feature bit to signal that we actually understand the message? Otherwise, we only act/log on the current error message. Still need catch up with the spec on my end...

There is no associated feature bit, it follows the it's ok to be odd rule (type 1). I think it's reasonable because those messages are for information purposes.