Lnd: Restart required to proces pending channels (opening en closing)

Created on 2 Feb 2018  路  42Comments  路  Source: lightningnetwork/lnd

Yesterday I've opened and closed a channel. In both times a restart was needed before they disappeared from the pendingchannels results. Also during the pending state wallet balance is not updated. A reboot of lnd solves this.

11 hours after initiating closing of the payment channel and 41 confirmations later

lnd@dawson:~$ lncli pendingchannels
{
    "total_limbo_balance": "5656",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "02ad23477886d4915890c77bdad39d430a204537ab0b7fef4969ebfac9342161aa",
                "channel_point": "5b546102c99a03ca5166f05a11f80ecb292ad070848acd127a53c816e7e8785e:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "closing_txid": "17258e5413c0747a7cc9d989ae1a845f50ac18221ce086a3997900b876731a17"
        }
    ],
    "pending_force_closing_channels": [
    ]
}
lnd@dawson:~$ lncli listchannels
{
    "channels": [
    ]
}
lnd@dawson:~$ lncli walletbalance
{
    "total_balance": "852464434",
    "confirmed_balance": "852464434",
    "unconfirmed_balance": "0"
}

After restart of LND

lnd@dawson:~$ lncli pendingchannels
{
    "total_limbo_balance": "0",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
    ]
}
lnd@dawson:~$ lncli listchannels
{
    "channels": [
    ]
}
lnd@dawson:~$ lncli walletbalance
{
    "total_balance": "852470090",
    "confirmed_balance": "852470090",
    "unconfirmed_balance": "0"
}

Sadly debug logs are already rotated because of high activity.

Running:
Bitcoin Core Daemon version v0.15.1.0-g7b57bc998f
lnd version 0.3.0-alpha (commit from februari 1st)

This issue also mentioned in chat on discord and slack but not yet reported as far as I know.

picture ronaldvdmeer

Most helpful comment

@halseth the pending channel was just removed and a new channel that I opened 30 minutes ago just changed its status without restarting the node. Thanks!

picture mariodian on 22 Mar 2018
🎉3

All 42 comments

I had the same issue opening a channel from a week old commit, to a host which had just been updated to the (big directory change) commit.

never got a funding tx response. But channel was showing in pending on both.

then channel was shown as open on newer version, but still pending on older.

once both implementations were on the latest commit, channels opened instantly and problem didn't recur.

bretton picture bretton on 2 Feb 2018

Just mass tested this. Below a couple of other channels. Opened 3 hours ago.

lnd@dawson:~$ lncli pendingchannels
{
    "total_limbo_balance": "0",
    "pending_open_channels": [
        {
            "channel": {
                "remote_node_pub": "0202bb5613077fbcaa45093ae659caf17a370a29477dbf364d6869651797d9441d",
                "channel_point": "6f569ad74b2bbf76be70165d95412bac4faa9d96cbd98fb9966cef751057747d:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "02081fc55f6fef6ce216f1e0eb3d717177f9f2fab2281fee1bb14556a742069e78",
                "channel_point": "28e11237c78b23ca7dd78a17017e83c128e3d0023888975d0de06a8108286225:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "020c6f449a676d90f65dc093a6d7560c9cc51720c70f7f65d9f460995da8c15aad",
                "channel_point": "818f324848619ba2192e484bdb1537852fcf6160ef8c6339b6e5cfb23c5669d3:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "0217c66d7f576b884c014cb1120f04ef5ccf601ff87d799e5225157042668fe0c2",
                "channel_point": "c3ad4c25a7e9f247770cae60bbc45105d6d7aad611fd0f203e2287aacadee440:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "021b0874c275eb6e5bec3eaf3ff1fd064fd1d9c4c72ddfa58645c05d70a35d60de",
                "channel_point": "29426bee140c7f153349bff6e8bd21ee37ee00b433fbefd0625713862365ed8f:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "021dcd5ec6cc0a00b537ae919d8aed683e9f0cb9776d535d45cc3bee6bec714939",
                "channel_point": "a831fecc96f6bdfddefd112b42db4d73b14f6027a90535d6903644a34eea2e2c:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "0228922d73ff8764502fd70e6e24229c2387b7d0ac472264b12697c668521610d3",
                "channel_point": "f91c5b405e63ef9176bee8707bb4338045e874fe8aaf198392ed1b19ef452c57:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "022bb58775e1aac549dcbd79239d0af97325243ada6708696f157c1dab11d97e61",
                "channel_point": "35aeb05dbcbca9e18e1af8863847d01ebd33a7942438320080da6b9613836e77:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "022c315d7588cf1714159915baae386dc87462b669a7036df33850e9c0a3265893",
                "channel_point": "b0d67db070514f20a3ce54c95a38511378e8d9e55283289f7b19e7e9cc6918af:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "0231eee2441073c86d38f6085aedaf2bb7ad3d43af4c0e2669c1edd1a7d566ce31",
                "channel_point": "59adfdba4ed05714f1ee48be6fceac50f9b2289347407235eec47b060ada0c42:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "023358548fe587f5c35dac43af5653b1451df65006eb0962d94af57b0a04ff4cf5",
                "channel_point": "fc0bb70b6d4e553c9647491ce3fa883e2ac9d85d1e374c652b63dd1d578f4730:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        }
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
    ]
}

Related funding_txid:

https://www.blocktrail.com/tBTC/tx/c3ad4c25a7e9f247770cae60bbc45105d6d7aad611fd0f203e2287aacadee440
https://www.blocktrail.com/tBTC/tx/29426bee140c7f153349bff6e8bd21ee37ee00b433fbefd0625713862365ed8f
https://www.blocktrail.com/tBTC/tx/a831fecc96f6bdfddefd112b42db4d73b14f6027a90535d6903644a34eea2e2c
https://www.blocktrail.com/tBTC/tx/f91c5b405e63ef9176bee8707bb4338045e874fe8aaf198392ed1b19ef452c57
https://www.blocktrail.com/tBTC/tx/35aeb05dbcbca9e18e1af8863847d01ebd33a7942438320080da6b9613836e77
https://www.blocktrail.com/tBTC/tx/b0d67db070514f20a3ce54c95a38511378e8d9e55283289f7b19e7e9cc6918af
https://www.blocktrail.com/tBTC/tx/59adfdba4ed05714f1ee48be6fceac50f9b2289347407235eec47b060ada0c42
https://www.blocktrail.com/tBTC/tx/fc0bb70b6d4e553c9647491ce3fa883e2ac9d85d1e374c652b63dd1d578f4730

The balance already seem to be adjusted as if the channels are up and running:

lnd@dawson:~$ lncli walletbalance 
{
    "total_balance": "852470090",
    "confirmed_balance": "852470090",
    "unconfirmed_balance": "0"
}

Right after opening the channels this was the walletbalance

lnd@dawson:~$ lncli walletbalance 
{
    "total_balance": "114432099",
    "confirmed_balance": "114432099",
    "unconfirmed_balance": "0"
}
ronaldvdmeer picture ronaldvdmeer on 2 Feb 2018 
lnd@dawson:~$ cat .lnd/lnd.conf 
[Application Options]
debuglevel=debug
externalip=X.X.X.X:19736
alias=XXXXXX
color=#00FF00
listen=0.0.0.0:19736

[Bitcoin]
bitcoin.active=1
bitcoin.testnet=1
bitcoin.node=bitcoind

[Bitcoind]
bitcoind.rpcuser=XXXXXX
bitcoind.rpcpass=XXXXXX
bitcoind.zmqpath=tcp://127.0.0.1:28333
ronaldvdmeer picture ronaldvdmeer on 2 Feb 2018

Are you running bitcoind with the txindex active?

Roasbeef picture Roasbeef on 2 Feb 2018

during the pending state wallet balance is not updated

This is due to the fact that we lock the inputs so they won't be shown as available balance until the funding transaction confirms, and the change output is created.

Roasbeef picture Roasbeef on 2 Feb 2018

Does this issue persist if you open channels greater than 10k satoshis (which is likely far too small to be able to properly pay for fees)?

Also do you have a log dump when you open those tiny channels?

Roasbeef picture Roasbeef on 2 Feb 2018

Also are you aware of channelbalance? That's the RPC that actually shows the available funds across all channels. walletbalance is only for _on-chain_ funds.

Roasbeef picture Roasbeef on 2 Feb 2018

Was your bitcoind node compiled _with zmq_ linked in?

Roasbeef picture Roasbeef on 2 Feb 2018

I'm not able to answer all the questions at this point but what I already can answer is the following

Are you running bitcoind with the txindex active?

Yes

Was your bitcoind node compiled with zmq linked in?

Not 100% sure. I've installed bitcoind from a precompiled repository and I think somewhere it was mentioned that by default bitcoind supports zmq when not explicitly turned off.

to be continued

ronaldvdmeer picture ronaldvdmeer on 2 Feb 2018

I've installed bitcoind from a precompiled repository

That repo needs to have had zmq compiled along with it, otherwise the backend won't work properly. If zmq wasn't linked in, then none of our notifications will work. On startup, do you see lnd successfully connect to the zmq socket of bitcoind?

Roasbeef picture Roasbeef on 2 Feb 2018

On startup, do you see lnd successfully connect to the zmq socket of bitcoind?

I think it does

2018-02-02 20:05:24.451 [INF] LNWL: Started listening for blocks via ZMQ on tcp://127.0.0.1:28333
2018-02-02 20:05:24.453 [INF] HSWC: Starting HTLC Switch
2018-02-02 20:05:24.455 [INF] NTFN: New block epoch subscription
2018-02-02 20:05:24.459 [INF] CNCT: Creating ChannelArbitrators for 1 active channels
2018-02-02 20:05:24.460 [DBG] CNCT: New ChainEventSubscription(id=0) for ChannelPoint(c3ad4c25a7e9f247770cae60bbc45105d6d7aad611fd0f203e2287aacadee440:0)
2018-02-02 20:05:24.460 [INF] NTFN: New block epoch subscription
2018-02-02 20:05:24.461 [INF] CNCT: Creating ChannelArbitrators for 10 closing channels
2018-02-02 20:05:24.461 [DBG] CNCT: Starting chain watcher for ChannelPoint(c3ad4c25a7e9f247770cae60bbc45105d6d7aad611fd0f203e2287aacadee440:0)
2018-02-02 20:05:24.556 [INF] NTFN: New spend subscription: utxo=818f324848619ba2192e484bdb1537852fcf6160ef8c6339b6e5cfb23c5669d3:0
2018-02-02 20:05:24.569 [INF] LNWL: Starting rescan from block 00000000000005c7f26f1e732935d156dca5346c85d3fb69b433437f9ccbc36b
2018-02-02 20:05:24.571 [INF] LNWL: Rescan finished at 1261910 (00000000000005c7f26f1e732935d156dca5346c85d3fb69b433437f9ccbc36b)
2018-02-02 20:05:24.571 [INF] LNWL: Catching up block hashes to height 1261910, this might take a while
2018-02-02 20:05:24.575 [INF] LNWL: Done catching up block hashes
ronaldvdmeer picture ronaldvdmeer on 2 Feb 2018

Once you can also those other questions, we'll be able to narrow down this case a good bit.

Roasbeef picture Roasbeef on 2 Feb 2018

Does this issue persist if you open channels greater than 10k satoshis (which is likely far too small to be able to properly pay for fees)?

Testing it right now

Bigger Channel cli used:

lnd@dawson:~$ lncli openchannel 023358548fe587f5c35dac43af5653b1451df65006eb0962d94af57b0a04ff4cf5 --local_amt=10000000
{
    "funding_txid": "5d3b02b8c62afa0892f725c4b6c61e9be44b8a143b6a1f99584d137df842e8ba"
}

Bigger Channel Details:

        {
            "channel": {
                "remote_node_pub": "023358548fe587f5c35dac43af5653b1451df65006eb0962d94af57b0a04ff4cf5",
                "channel_point": "5d3b02b8c62afa0892f725c4b6c61e9be44b8a143b6a1f99584d137df842e8ba:0",
                "capacity": "10000000",
                "local_balance": "9995656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        }

Also do you have a log dump when you open those tiny channels?

Tiny Channel cli used:

lnd@dawson:~$ lncli openchannel 0231eee2441073c86d38f6085aedaf2bb7ad3d43af4c0e2669c1edd1a7d566ce31 --local_amt=10000
{
    "funding_txid": "8fcf1f88351a63da367ce5c6fad825ab5c0d6160b13b273c579469928b1539c7"
}

Tiny Channel details:

        {
            "channel": {
                "remote_node_pub": "0231eee2441073c86d38f6085aedaf2bb7ad3d43af4c0e2669c1edd1a7d566ce31",
                "channel_point": "8fcf1f88351a63da367ce5c6fad825ab5c0d6160b13b273c579469928b1539c7:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },

log (expires in one week): https://pastebin.com/rm1u17GH

To keep the log readable I've removed a couple of discovery (DISC) lines as you can see in the command used (first line in pastebin).

ronaldvdmeer picture ronaldvdmeer on 3 Feb 2018

So far, at least one hour later, nothing changed. All pending.

lnd@dawson:~$ lncli pendingchannels
{
    "total_limbo_balance": "5005656",
    "pending_open_channels": [
        {
            "channel": {
                "remote_node_pub": "0231eee2441073c86d38f6085aedaf2bb7ad3d43af4c0e2669c1edd1a7d566ce31",
                "channel_point": "8fcf1f88351a63da367ce5c6fad825ab5c0d6160b13b273c579469928b1539c7:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        },
        {
            "channel": {
                "remote_node_pub": "023358548fe587f5c35dac43af5653b1451df65006eb0962d94af57b0a04ff4cf5",
                "channel_point": "5d3b02b8c62afa0892f725c4b6c61e9be44b8a143b6a1f99584d137df842e8ba:0",
                "capacity": "10000000",
                "local_balance": "9995656",
                "remote_balance": "0"
            },
            "confirmation_height": 0,
            "commit_fee": "4344",
            "commit_weight": "600",
            "fee_per_kw": "6000"
        }
    ],
    "pending_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "02081fc55f6fef6ce216f1e0eb3d717177f9f2fab2281fee1bb14556a742069e78",
                "channel_point": "d0d9f6bbcbaf2e1766d17a0ed68f6dc3ab3ff884836f4c5e2b0a82f3cd6b2b13:0",
                "capacity": "10000000",
                "local_balance": "5000000",
                "remote_balance": "0"
            },
            "closing_txid": "b85eac3ac2062049a9568b52b934f99285dae39509aabc6991c5a0fb805a2369"
        },
        {
            "channel": {
                "remote_node_pub": "0217c66d7f576b884c014cb1120f04ef5ccf601ff87d799e5225157042668fe0c2",
                "channel_point": "c3ad4c25a7e9f247770cae60bbc45105d6d7aad611fd0f203e2287aacadee440:0",
                "capacity": "10000",
                "local_balance": "5656",
                "remote_balance": "0"
            },
            "closing_txid": "f6731d1dec9937752fdd5604e2dd13d3878bb74dcb7203a2f7ee1ce0d1035ef9"
        }
    ],
    "pending_force_closing_channels": [
    ]
}
lnd@dawson:~$ lncli channelbalance
{
    "balance": "0"
}
ronaldvdmeer picture ronaldvdmeer on 3 Feb 2018

Do you see newly mined blocks being detected by lnd? Something is up with your node set up.

Roasbeef picture Roasbeef on 3 Feb 2018

For example, the logs that you linked above spans over an hour in time. However, I don't see any new block notifications being received. If no new blocks are discovered, then we won't be able to detect when new things have been confirmed, spent, etc.

Roasbeef picture Roasbeef on 3 Feb 2018

The log is only 1 minute :)

ronaldvdmeer picture ronaldvdmeer on 3 Feb 2018

Ahh, lol nvm then :)

But _do_ you see new blocks being discovered? I'm concluding something is off with your setup as I'm unable to reproduce myself, and don't have this issue on any of my other existing nodes.

Roasbeef picture Roasbeef on 3 Feb 2018

I'm checking it but need to wait for the next block because the log is rotating very quickly. Only have about 4 log-files which only cover a couple of minutes. Should grepping on Block be sufficient?

ronaldvdmeer picture ronaldvdmeer on 3 Feb 2018

Yes or grepping for NTFN

Roasbeef picture Roasbeef on 3 Feb 2018

My bitcoind processed the latest block just around 15 minutes ago. Shouldn't take very long

2018-02-03 01:44:27 UpdateTip: new best=000000000000023a31680fc0e34d4d535f0ce6323572f52424c1ee6a06da7048 height=1261937 version=0x20000000 log2_work=69.734867 tx=17155665 date='2018-02-03 01:43:59' progress=1.000000 cache=3.3MiB(23763txo)
ronaldvdmeer picture ronaldvdmeer on 3 Feb 2018

Yes or grepping for NTFN

You're right. Only when lnd is restarted it is receiving the latest blocks from bitcoind

ronaldvdmeer picture ronaldvdmeer on 3 Feb 2018

So it receives blocks, but then _stops_ getting new new blocks at some point? Only upon restart does it continue to get new blocks?

Roasbeef picture Roasbeef on 3 Feb 2018

Correct indeed! I restarted bitcoind and lnd. LND immediately started syncing again. But as soon as the next block was processed by bitcoind, lnd didn't seem to detect it

ronaldvdmeer picture ronaldvdmeer on 3 Feb 2018

When I start LND I do get some blocks out of order error. Not sure if this is related.

See: https://pastebin.com/KS4Npj6g

ronaldvdmeer picture ronaldvdmeer on 3 Feb 2018

What does your bitcoind.conf look like?

Roasbeef picture Roasbeef on 3 Feb 2018 
root@dawson:/data# cat /etc/bitcoin/bitcoin-testnet.conf 
# [core]
pid=/run/bitcoind/bitcoind-testnet.pid
txindex=1
datadir=/data/bitcoin-testnet

# [network]
port=18333

# [debug]
testnet=1

# [rpc]
server=1
rest=1
rpcuser=xxxxx
rpcpassword=xxxxxx
rpcallowip=127.0.0.1

# [zmq]
zmqpubhashtx=tcp://127.0.0.1:28333
zmqpubrawtx=tcp://127.0.0.1:28333

bitcoind (user bitcoin)

/usr/bin/bitcoind -daemon -conf=/etc/bitcoin/bitcoin-testnet.conf

lnd (user lnd)

/bin/sh -c 'export GOPATH=~/gocode && export PATH=$PATH:$GOPATH/bin && /home/lnd/gocode/bin/lnd --configfile=/home/lnd/.lnd/lnd.conf &'
ronaldvdmeer picture ronaldvdmeer on 3 Feb 2018

You're missing this line: 

zmqpubrawblock=tcp://127.0.0.1:18501

Related to #702. Without that line your bitcoind node won't notify for new blocks. Once that PR is merged, I'll close this.

Roasbeef picture Roasbeef on 3 Feb 2018

You're missing this line:

This would be really stupid from my side as it is explicitly mentioned in the installation documentation ... Testing this right now

ronaldvdmeer picture ronaldvdmeer on 3 Feb 2018

Still not able to confirm if this works due to some pending channels that don't seem to close.
However, the install.md now mentions a port that doesn't match the text above.

zmqpubrawblock=tcp://127.0.0.1:18501
zmqpubrawtx=tcp://127.0.0.1:18501

Shouldn't that be :28332?

ronaldvdmeer picture ronaldvdmeer on 4 Feb 2018

The pending channels won't close if you're not receiving block notifications. If you didn't have zmqpubrawblock set, then you won't receive new block notifications.

Shouldn't that be :28332?

Depends on how you configure your set up.

Roasbeef picture Roasbeef on 4 Feb 2018

yeah but in the install.md port 28332 is mentioned in the text above. However the example is has another port. Might cause some confusion

ronaldvdmeer picture ronaldvdmeer on 4 Feb 2018

You're missing this line:

zmqpubrawblock=tcp://127.0.0.1:18501
Related to #702. Without that line your bitcoind node won't notify for new blocks. Once that PR is merged, I'll close this.

Confirmed this was indeed the problem. Now it works as intended. Thank you @Roasbeef

ronaldvdmeer picture ronaldvdmeer on 4 Feb 2018
👍1

馃憤

Will fix the docs to ensure they're consistent as well!

Roasbeef picture Roasbeef on 4 Feb 2018
👍1

I use a bitcoind binary from the official repo, my bitcoin.conf looks like:

server=1
listen=1
daemon=1
txindex=1
disablewallet=1

onlynet=ipv4

zmqpubrawblock=tcp://127.0.0.1:18501
zmqpubrawtx=tcp://127.0.0.1:18501

my lnd.conf contains:

bitcoind.zmqpath=tcp://127.0.0.1:18501

lnd logs show this:

[INF] LNWL: Started listening for blocks via ZMQ on tcp://127.0.0.1:18501

yet I always have to restart my lightning node to process pending channels.

Any idea what could be wrong?

mariodian picture mariodian on 22 Mar 2018

@mariodian have you set

# bitcoin.conf
rpcuser=xxxxx
rpcpassword=xxxxxx

and

# lnd.conf
bitcoind.rpcuser=xxxxx
bitcoind.rpcpass=xxxxxx

?

cfromknecht picture cfromknecht on 22 Mar 2018

I have.

Oddly, the last channel stays pending even after the restart. Previous channels have changed their state once the node was restarted.

mariodian picture mariodian on 22 Mar 2018

Here are logs related to the opening channel tx:

cat lnd.log | grep 1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184
2018-03-21 13:44:26.712 [INF] FNDG: Generated ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) for pendingID(5b6bfb4a4957e723afa77ba7c0d9288e9e2623500c49b14d77f41d47377c0730)
2018-03-21 13:44:29.002 [INF] LNWL: Broadcasting funding tx for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): (*wire.MsgTx)(0xc502a8b500)({
2018-03-21 13:44:29.003 [INF] LNWL: Inserting unconfirmed transaction 1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184
2018-03-21 13:44:29.188 [INF] CNCT: Creating new ChannelArbitrator for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-21 13:44:29.188 [INF] CNCT: ChannelArbitrator(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): starting state=StateDefault
2018-03-21 13:44:29.274 [INF] NTFN: New spend subscription: utxo=1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0
2018-03-21 13:44:29.276 [INF] FNDG: Finalizing pendingID(5b6bfb4a4957e723afa77ba7c0d9288e9e2623500c49b14d77f41d47377c0730) over ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0), waiting for channel open on-chain
2018-03-21 13:44:29.277 [INF] CNCT: Close observer for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) active
2018-03-21 13:44:29.375 [INF] NTFN: New confirmations subscription: txid=1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184, numconfs=3
2018-03-21 13:44:29.375 [INF] FNDG: Waiting for funding tx (1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184) to reach 3 confirmations
2018-03-21 13:50:47.868 [INF] LNWL: Marking unconfirmed transaction 1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184 mined in block 514487
2018-03-21 14:06:27.038 [INF] NTFN: Dispatching 3 conf notification for 1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184
2018-03-21 14:06:27.038 [INF] FNDG: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is now active: ChannelID(8431aa607fe488be93c34e553aff621fdf1f0be5d14d99f376140d2b01572a1d)
2018-03-21 14:06:27.839 [INF] CRTR: New channel discovered! Link connects 0207481a19a3f51a48f134e95afa67cfeffdb38a99b5ad3494a320c4918aaaf579 and 02241e1d480fcedaa1268574d530ef8ed5545bacdcd391e40ac58cbed30d001d40 with ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): chan_id=565684438905389056, capacity=0.00648661 BTC
2018-03-21 14:06:28.204 [INF] NTFN: New confirmations subscription: txid=1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184, numconfs=6
2018-03-21 14:06:39.990 [INF] PEER: New channel active ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) with NodeKey(0207481a19a3f51a48f134e95afa67cfeffdb38a99b5ad3494a320c4918aaaf579)
2018-03-21 14:06:39.993 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is starting
2018-03-21 14:06:39.993 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-21 14:06:39.993 [INF] HSWC: HTLC manager for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) started, bandwidth=641450000 mSAT
2018-03-21 14:42:49.044 [INF] NTFN: Dispatching 6 conf notification for 1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184
2018-03-21 14:42:49.044 [INF] FNDG: Announcing ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0), short_chan_id=(*lnwire.ShortChannelID)(0xc4f20320b0)(514487:1004:0)
2018-03-21 16:05:49.274 [INF] NTFN: New spend subscription: utxo=1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0
2018-03-21 16:05:49.276 [INF] CNCT: Close observer for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) active
2018-03-21 16:05:49.939 [INF] CNCT: ChannelArbitrator(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): starting state=StateDefault
2018-03-21 16:05:52.149 [INF] PEER: NodeKey(0207481a19a3f51a48f134e95afa67cfeffdb38a99b5ad3494a320c4918aaaf579) loading ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-21 16:05:52.301 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is starting
2018-03-21 16:05:52.301 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-21 16:05:52.303 [INF] HSWC: HTLC manager for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) started, bandwidth=641450000 mSAT
2018-03-21 16:05:52.303 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-21 16:05:53.022 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): resending FundingLocked message to peer
2018-03-21 16:05:53.023 [INF] HSWC: Received re-establishment message from remote side for channel(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-21 20:10:11.414 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is stopping
2018-03-21 20:10:11.415 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) has exited
2018-03-21 20:10:31.123 [INF] PEER: NodeKey(0207481a19a3f51a48f134e95afa67cfeffdb38a99b5ad3494a320c4918aaaf579) loading ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-21 20:10:31.126 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is starting
2018-03-21 20:10:31.126 [INF] HSWC: HTLC manager for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) started, bandwidth=641450000 mSAT
2018-03-21 20:10:31.126 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-21 20:10:31.126 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-21 20:10:32.088 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): resending FundingLocked message to peer
2018-03-21 20:10:32.088 [INF] HSWC: Received re-establishment message from remote side for channel(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-21 20:20:56.710 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 1250 sat/kw
2018-03-21 20:39:17.685 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 1000 sat/kw
2018-03-21 21:21:30.328 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 1250 sat/kw
2018-03-21 21:43:24.433 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 2250 sat/kw
2018-03-21 23:16:01.407 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 2500 sat/kw
2018-03-22 04:56:18.295 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 1250 sat/kw
2018-03-22 05:26:10.364 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 2250 sat/kw
2018-03-22 05:47:54.034 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 1250 sat/kw
2018-03-22 06:51:11.238 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 1500 sat/kw
2018-03-22 07:08:45.353 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 2250 sat/kw
2018-03-22 07:19:34.669 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 1750 sat/kw
2018-03-22 08:56:03.338 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 2250 sat/kw
2018-03-22 09:14:52.271 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 2000 sat/kw
2018-03-22 09:37:09.584 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 2250 sat/kw
2018-03-22 10:01:06.314 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 2000 sat/kw
2018-03-22 10:52:37.805 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 2250 sat/kw
2018-03-22 15:34:41.576 [INF] HSWC: ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): updating commit fee to 1000 sat/kw
2018-03-22 17:09:14.467 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) has exited
2018-03-22 17:09:14.518 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is stopping
2018-03-22 17:09:32.744 [INF] NTFN: New spend subscription: utxo=1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0
2018-03-22 17:09:32.746 [INF] CNCT: Close observer for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) active
2018-03-22 17:09:33.057 [INF] CNCT: ChannelArbitrator(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): starting state=StateDefault
2018-03-22 17:09:34.658 [INF] PEER: NodeKey(0207481a19a3f51a48f134e95afa67cfeffdb38a99b5ad3494a320c4918aaaf579) loading ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 17:09:34.659 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is starting
2018-03-22 17:09:34.660 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 17:09:34.660 [INF] HSWC: HTLC manager for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) started, bandwidth=641450000 mSAT
2018-03-22 17:09:34.660 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 17:09:35.872 [INF] HSWC: Received re-establishment message from remote side for channel(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 17:15:38.507 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) has exited
2018-03-22 17:16:03.431 [INF] NTFN: New spend subscription: utxo=1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0
2018-03-22 17:16:03.433 [INF] CNCT: Close observer for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) active
2018-03-22 17:16:03.541 [INF] CNCT: ChannelArbitrator(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): starting state=StateDefault
2018-03-22 17:16:04.746 [INF] PEER: NodeKey(0207481a19a3f51a48f134e95afa67cfeffdb38a99b5ad3494a320c4918aaaf579) loading ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 17:16:04.750 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is starting
2018-03-22 17:16:04.750 [INF] HSWC: HTLC manager for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) started, bandwidth=641450000 mSAT
2018-03-22 17:16:04.750 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 17:16:04.750 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 17:16:05.904 [INF] HSWC: Received re-establishment message from remote side for channel(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 19:14:55.849 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) has exited
2018-03-22 19:14:55.849 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is stopping
2018-03-22 19:18:24.689 [INF] NTFN: New spend subscription: utxo=1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0
2018-03-22 19:18:24.705 [INF] CNCT: Close observer for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) active
2018-03-22 19:18:25.217 [INF] CNCT: ChannelArbitrator(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): starting state=StateDefault
2018-03-22 19:18:27.136 [INF] PEER: NodeKey(0207481a19a3f51a48f134e95afa67cfeffdb38a99b5ad3494a320c4918aaaf579) loading ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 19:18:27.202 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is starting
2018-03-22 19:18:27.202 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 19:18:27.219 [INF] HSWC: HTLC manager for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) started, bandwidth=641450000 mSAT
2018-03-22 19:18:27.219 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 19:18:28.109 [INF] HSWC: Received re-establishment message from remote side for channel(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 19:19:05.486 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) has exited
2018-03-22 19:19:05.487 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is stopping
2018-03-22 19:19:34.101 [INF] NTFN: New spend subscription: utxo=1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0
2018-03-22 19:19:34.103 [INF] CNCT: Close observer for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) active
2018-03-22 19:19:34.306 [INF] CNCT: ChannelArbitrator(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0): starting state=StateDefault
2018-03-22 19:19:36.483 [INF] PEER: NodeKey(0207481a19a3f51a48f134e95afa67cfeffdb38a99b5ad3494a320c4918aaaf579) loading ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 19:19:36.486 [INF] HSWC: ChannelLink(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) is starting
2018-03-22 19:19:36.486 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 19:19:36.486 [INF] HSWC: HTLC manager for ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0) started, bandwidth=641450000 mSAT
2018-03-22 19:19:36.486 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)
2018-03-22 19:19:37.538 [INF] HSWC: Received re-establishment message from remote side for channel(1d2a57012b0d1476f3994dd1e50b1fdf1f62ff3a554ec393be88e47f60aa3184:0)

Not sure if that helps.

mariodian picture mariodian on 22 Mar 2018

@mariodian From the logs it looks like the channel is operating as expected. Could you set debuglevel=debug in your lnd.conf and past the logs after a restart? Thanks!

halseth picture halseth on 22 Mar 2018

@halseth sorry for the confusion, I posted the wrong channel logs.

This is the right logs:

$ cat lnd.log | grep aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3
2018-03-21 00:06:57.211 [INF] FNDG: completing pendingID(888c8dc31dd2d25376b3e1aaf0f1a26b6f69c846e911cd951c7512ed69863306) with ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 00:06:57.264 [INF] FNDG: sending FundingSigned for pendingID(888c8dc31dd2d25376b3e1aaf0f1a26b6f69c846e911cd951c7512ed69863306) over ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 00:06:57.264 [INF] CNCT: Creating new ChannelArbitrator for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 00:06:57.264 [INF] CNCT: ChannelArbitrator(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0): starting state=StateDefault
2018-03-21 00:06:57.314 [INF] NTFN: New spend subscription: utxo=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0
2018-03-21 00:06:57.506 [INF] CNCT: Close observer for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) active
2018-03-21 00:06:57.506 [INF] NTFN: New confirmations subscription: txid=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3, numconfs=3
2018-03-21 00:06:57.506 [INF] FNDG: Waiting for funding tx (aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3) to reach 3 confirmations
2018-03-21 00:06:58.300 [INF] PEER: NodeKey(027ccec61f4bf1fafb5156931da6527dc104ec3613dd4f4050161d89dd76ab494c) loading ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 00:06:58.303 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is starting
2018-03-21 00:06:58.303 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 00:06:58.303 [INF] HSWC: HTLC manager for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) started, bandwidth=0 mSAT
2018-03-21 00:06:58.303 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 00:07:28.304 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) has exited
2018-03-21 00:07:28.305 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is stopping
2018-03-21 00:09:12.848 [INF] PEER: NodeKey(027ccec61f4bf1fafb5156931da6527dc104ec3613dd4f4050161d89dd76ab494c) loading ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 00:09:12.851 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is starting
2018-03-21 00:09:12.851 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 00:09:12.851 [INF] HSWC: HTLC manager for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) started, bandwidth=0 mSAT
2018-03-21 00:09:12.851 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 00:09:42.853 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) has exited
2018-03-21 00:09:42.853 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is stopping
2018-03-21 03:04:15.057 [INF] PEER: NodeKey(027ccec61f4bf1fafb5156931da6527dc104ec3613dd4f4050161d89dd76ab494c) loading ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 03:04:15.176 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is starting
2018-03-21 03:04:15.177 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 03:04:15.178 [INF] HSWC: HTLC manager for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) started, bandwidth=0 mSAT
2018-03-21 03:04:15.179 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 03:04:45.180 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) has exited
2018-03-21 03:04:45.180 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is stopping
2018-03-21 03:55:23.077 [INF] PEER: NodeKey(027ccec61f4bf1fafb5156931da6527dc104ec3613dd4f4050161d89dd76ab494c) loading ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 03:55:23.130 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is starting
2018-03-21 03:55:23.130 [INF] HSWC: HTLC manager for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) started, bandwidth=0 mSAT
2018-03-21 03:55:23.130 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 03:55:23.130 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 03:55:53.131 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) has exited
2018-03-21 03:55:53.132 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is stopping
2018-03-21 16:05:34.457 [WRN] FNDG: fundingManager shutting down, stopping funding flow for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 16:05:48.768 [INF] FNDG: Waiting for funding tx (aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3) to reach 3 confirmations
2018-03-21 16:05:48.768 [INF] NTFN: New confirmations subscription: txid=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3, numconfs=3
2018-03-21 16:05:49.388 [INF] NTFN: New spend subscription: utxo=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0
2018-03-21 16:05:49.392 [INF] CNCT: Close observer for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) active
2018-03-21 16:05:49.941 [INF] CNCT: ChannelArbitrator(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0): starting state=StateDefault
2018-03-21 23:42:17.286 [INF] PEER: NodeKey(027ccec61f4bf1fafb5156931da6527dc104ec3613dd4f4050161d89dd76ab494c) loading ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 23:42:17.369 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is starting
2018-03-21 23:42:17.370 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 23:42:17.370 [INF] HSWC: HTLC manager for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) started, bandwidth=0 mSAT
2018-03-21 23:42:17.370 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-21 23:42:47.371 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) has exited
2018-03-21 23:42:47.371 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is stopping
2018-03-22 00:12:15.437 [INF] PEER: NodeKey(027ccec61f4bf1fafb5156931da6527dc104ec3613dd4f4050161d89dd76ab494c) loading ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-22 00:12:15.463 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is starting
2018-03-22 00:12:15.463 [INF] HSWC: HTLC manager for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) started, bandwidth=0 mSAT
2018-03-22 00:12:15.463 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-22 00:12:15.463 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-22 00:12:45.464 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) has exited
2018-03-22 00:12:45.465 [INF] HSWC: ChannelLink(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) is stopping
2018-03-22 17:09:14.467 [WRN] FNDG: fundingManager shutting down, stopping funding flow for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-22 17:09:32.140 [INF] FNDG: Waiting for funding tx (aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3) to reach 3 confirmations
2018-03-22 17:09:32.140 [INF] NTFN: New confirmations subscription: txid=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3, numconfs=3
2018-03-22 17:09:32.944 [INF] NTFN: New spend subscription: utxo=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0
2018-03-22 17:09:32.949 [INF] CNCT: Close observer for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) active
2018-03-22 17:09:33.050 [INF] CNCT: ChannelArbitrator(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0): starting state=StateDefault
2018-03-22 17:15:38.507 [WRN] FNDG: fundingManager shutting down, stopping funding flow for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-22 17:16:02.762 [INF] FNDG: Waiting for funding tx (aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3) to reach 3 confirmations
2018-03-22 17:16:02.762 [INF] NTFN: New confirmations subscription: txid=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3, numconfs=3
2018-03-22 17:16:03.066 [INF] NTFN: New spend subscription: utxo=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0
2018-03-22 17:16:03.067 [INF] CNCT: Close observer for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) active
2018-03-22 17:16:03.546 [INF] CNCT: ChannelArbitrator(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0): starting state=StateDefault
2018-03-22 19:14:55.849 [WRN] FNDG: fundingManager shutting down, stopping funding flow for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-22 19:18:24.169 [INF] FNDG: Waiting for funding tx (aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3) to reach 3 confirmations
2018-03-22 19:18:24.169 [INF] NTFN: New confirmations subscription: txid=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3, numconfs=3
2018-03-22 19:18:24.890 [INF] NTFN: New spend subscription: utxo=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0
2018-03-22 19:18:24.894 [INF] CNCT: Close observer for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) active
2018-03-22 19:18:25.227 [INF] CNCT: ChannelArbitrator(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0): starting state=StateDefault
2018-03-22 19:19:05.486 [WRN] FNDG: fundingManager shutting down, stopping funding flow for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-22 19:19:33.703 [INF] NTFN: New confirmations subscription: txid=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3, numconfs=3
2018-03-22 19:19:33.703 [INF] FNDG: Waiting for funding tx (aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3) to reach 3 confirmations
2018-03-22 19:19:34.301 [INF] NTFN: New spend subscription: utxo=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0
2018-03-22 19:19:34.307 [INF] CNCT: Close observer for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) active
2018-03-22 19:19:35.443 [INF] CNCT: ChannelArbitrator(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0): starting state=StateDefault
2018-03-22 21:43:17.476 [WRN] FNDG: fundingManager shutting down, stopping funding flow for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)
2018-03-22 21:43:30.268 [INF] NTFN: New confirmations subscription: txid=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3, numconfs=3
2018-03-22 21:43:30.268 [INF] FNDG: Waiting for funding tx (aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3) to reach 3 confirmations
2018-03-22 21:43:30.773 [INF] NTFN: New spend subscription: utxo=aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0
2018-03-22 21:43:30.777 [INF] CNCT: Close observer for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0) active
2018-03-22 21:43:31.041 [INF] CNCT: ChannelArbitrator(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0): starting state=StateDefault
2018-03-22 21:50:40.600 [WRN] FNDG: fundingManager shutting down, stopping funding flow for ChannelPoint(aa82f10598a2513913aeaa16d0fad3e8a6d63bdaac5f5cf0c72cdd2c0edfe4b3:0)

The txid doesn't even exist in mempool.

// edit

I checked my shell history and I never even tried to open a channel with the node (027ccec61f4bf1fafb5156931da6527dc104ec3613dd4f4050161d89dd76ab494c).

mariodian picture mariodian on 22 Mar 2018

So it looks like this node opened a channel to you, but never broadcasted the funding transaction. Your node should remove it after 288 blocks (~48 hrs). Let me know if that happens or not!

halseth picture halseth on 22 Mar 2018

@halseth the pending channel was just removed and a new channel that I opened 30 minutes ago just changed its status without restarting the node. Thanks!

mariodian picture mariodian on 22 Mar 2018
🎉3
Was this page helpful?
0 / 5 - 0 ratings

Related issues

BitBargain picture BitBargain  路  3Comments
hxsquid picture hxsquid  路  3Comments
Roasbeef picture Roasbeef  路  3Comments
zyp picture zyp  路  4Comments
alexbosworth picture alexbosworth  路  3Comments