Force closed channels didn't appear on 'pendingchannels' and funds do not appear on wallet balance.

[joaodealmeida]

Background

After force-closing 2 channels, they didn't appeared on lncli pendingchannels and I didn't receive the funds yet even though the CLTV delay as been reached and the sweep tx have been broadcasted.

Your environment

• version of lnd
  lncli version 0.4.1 commit=bdf3f4d7753ce950bd14ed56ad96c12097f1b4c9
• which operating system (uname -a on *Nix)
  Linux feup.s1 3.16.0-4-amd64 Fix name typo in README #1 SMP Debian 3.16.51-3 (2017-12-13) x86_64 GNU/Linux
• version of btcd, bitcoind, or other backend
  0.16.0

Steps to reproduce

/lncli closechannel --sat_per_byte=1 --funding_txid=7b6e054254b212456d2a45dc6469a0a317ebdff98366c54d472b0dacf360a5c4 --output_index=1 --force
{
"closing_txid": "c901b260059ba0ee9cbbd3d66ec1964d53c30a1ecc082cc644bd12406a6e5158"
}

lncli closechannel --sat_per_byte=1 --funding_txid=2c0ae5e3a5236802c1d65a7797256d9471d982c79b5b662c254f099da80b2dae --output_index=1 --force
{
"closing_txid": "edae116219d1e7b6be8e0620e53fa0356202046e1ad2d155f2aba2f91c57df49"
}

https://www.robtex.com/lightning/channel/564789436490711041
https://www.robtex.com/lightning/channel/564845511538114561

LND LOGS: https://joaoalmeida.me/lnd.log

Expected behaviour

~ Channels close tx's appear on lncli pendingchannels command.
~ Channels local funds to appear on wallet balance.

Actual behaviour

~ Channels closing tx's didn't appear on pendingchannels list.
~ Wallet didn't receive the funds.

[Roasbeef]

The funds for that first channel have already been swept: https://www.smartbit.com.au/tx/f01d489fff74c7d2690831dbfd8d67ca349b59da3e730135505a775a408fced3

The funds for the second channel have also already been swept: https://www.smartbit.com.au/tx/7448d0d2e3b8858c4806a95ea06b1be849afd4d912373d536e032b1212cbdbf6

[joaodealmeida]

I'm aware. I stated that on my background, however I don't see any funds on my wallet balance.

[Roasbeef]

How are you calculating your wallet balance? Are the transactions showing up in listchaintxns?

[Roasbeef]

Looking at the logs, we see that both outputs are picked up to be swept by the utxo nursery:

2018-05-05 19:11:35.217 [INF] PEER: ChannelPoint(2c0ae5e3a5236802c1d65a7797256d9471d982c79b5b662c254f099da80b2dae:1) is now closed at height 521358
2018-05-05 19:11:35.218 [INF] UTXN: Transitioning (crib -> kid) output for chan_point=2c0ae5e3a5236802c1d65a7797256d9471d982c79b5b662c254f099da80b2dae:1 at height_index=521658
2018-05-05 19:11:35.218 [INF] PEER: ChannelPoint(7b6e054254b212456d2a45dc6469a0a317ebdff98366c54d472b0dacf360a5c4:1) is now closed at height 521358
2018-05-05 19:11:35.219 [INF] UTXN: Transitioning (crib -> kid) output for chan_point=7b6e054254b212456d2a45dc6469a0a317ebdff98366c54d472b0dacf360a5c4:1 at height_index=521502
2018-05-05 19:11:35.291 [INF] NTFN: New spend subscription: utxo=edae116219d1e7b6be8e0620e53fa0356202046e1ad2d155f2aba2f91c57df49:0
2018-05-05 19:11:35.430 [INF] CNCT: *contractcourt.commitSweepResolver(7b6e054254b212456d2a45dc6469a0a317ebdff98366c54d472b0dacf360a5c4:1): waiting for commit output to be swept
2018-05-05 19:11:35.567 [INF] CNCT: *contractcourt.commitSweepResolver(2c0ae5e3a5236802c1d65a7797256d9471d982c79b5b662c254f099da80b2dae:1): waiting for commit output to be swept

They're then marked as closed once the nursery sweeps them:

2018-05-05 19:13:35.181 [INF] NTFN: Dispatching 1 conf notification for f01d489fff74c7d2690831dbfd8d67ca349b59da3e730135505a775a408fced3
2018-05-05 19:13:35.181 [INF] NTFN: Dispatching 1 conf notification for 7448d0d2e3b8858c4806a95ea06b1be849afd4d912373d536e032b1212cbdbf6
2018-05-05 19:13:35.181 [INF] CNCT: ChannelPoint(2c0ae5e3a5236802c1d65a7797256d9471d982c79b5b662c254f099da80b2dae:1) commit tx is fully resolved, at height: 521359
2018-05-05 19:13:35.182 [INF] UTXN: Attempting to graduate height=521359: num_kids=0, num_babies=0
2018-05-05 19:13:35.184 [INF] CNCT: ChannelPoint(7b6e054254b212456d2a45dc6469a0a317ebdff98366c54d472b0dacf360a5c4:1) commit tx is fully resolved, at height: 521359
2018-05-05 19:13:35.203 [INF] CNCT: ChannelArbitrator(2c0ae5e3a5236802c1d65a7797256d9471d982c79b5b662c254f099da80b2dae:1): a contract has been fully resolved!
2018-05-05 19:13:35.203 [INF] CNCT: ChannelArbitrator(2c0ae5e3a5236802c1d65a7797256d9471d982c79b5b662c254f099da80b2dae:1): all contracts fully resolved, exiting
2018-05-05 19:13:35.203 [INF] CNCT: Marking ChannelPoint(2c0ae5e3a5236802c1d65a7797256d9471d982c79b5b662c254f099da80b2dae:1) fully resolved
2018-05-05 19:13:35.204 [INF] CNCT: ChannelArbitrator(7b6e054254b212456d2a45dc6469a0a317ebdff98366c54d472b0dacf360a5c4:1): a contract has been fully resolved!
2018-05-05 19:13:35.204 [INF] CNCT: ChannelArbitrator(7b6e054254b212456d2a45dc6469a0a317ebdff98366c54d472b0dacf360a5c4:1): all contracts fully resolved, exiting
2018-05-05 19:13:35.204 [INF] CNCT: Marking ChannelPoint(7b6e054254b212456d2a45dc6469a0a317ebdff98366c54d472b0dacf360a5c4:1) fully resolved

The odd thing here is that they should've have been swept for a few hundred blocks:

2018-05-05 19:11:35.217 [INF] PEER: ChannelPoint(2c0ae5e3a5236802c1d65a7797256d9471d982c79b5b662c254f099da80b2dae:1) is now closed at height 521358
2018-05-05 19:11:35.218 [INF] UTXN: Transitioning (crib -> kid) output for chan_point=2c0ae5e3a5236802c1d65a7797256d9471d982c79b5b662c254f099da80b2dae:1 at height_index=521658
2018-05-05 19:11:35.218 [INF] PEER: ChannelPoint(7b6e054254b212456d2a45dc6469a0a317ebdff98366c54d472b0dacf360a5c4:1) is now closed at height 521358
2018-05-05 19:11:35.219 [INF] UTXN: Transitioning (crib -> kid) output for chan_point=7b6e054254b212456d2a45dc6469a0a317ebdff98366c54d472b0dacf360a5c4:1 at height_index=521502

[Roasbeef]

When opening the channel? Did you set a custom remote csv value?

[Roasbeef]

Do you have logs after the height of 521658? (which just recently passed)

[Roasbeef]

Did you have multiple nodes running with the same seed and channel state?

[Roasbeef]

Actually...looking at the scripts the output was actually revoked! The witness of both spends has a 1, meaning that it took the revocation path!

[joaodealmeida]

I don't really remember, but I'm almost certain that I didn't.
Yes, it's possible. https://joaoalmeida.me/lnd_2.log

I can't start the node right, get the following and lnd shutsdown

2018-05-07 20:33:53.346 [ERR] UTXN: Failed to sweep 1 kindergarten outputs at height=521658: Transaction rejected: output already spent
2018-05-07 20:33:53.347 [ERR] UTXN: Failed to graduate outputs at height=521658: Transaction rejected: output already spent
2018-05-07 20:35:05.421 [INF] NTFN: Cancelling epoch notification, epoch_id=2
2018-05-07 20:35:05.422 [ERR] SRVR: unable to start server: Transaction rejected: output already spent

Transaction rejected: output already spent

I don't have multiple nodes running on the same seed/state.

[joaodealmeida]

It's a channel with bitrefill so might be interesting to check their logs.
Does it means my node had an outdated signed tx in order for bitrefill's node to be able to take the revocation path?

[Roasbeef]

Well the scripts don't lie, you broadcasted a revoke state unfortunately. lnd can't start up atm as a case of a failed breach attempt wasn't factored in. There's an open issue that will allow us to detect such a state and prevent broadcasts once implemented.

…

On Mon, May 7, 2018, 1:36 PM João Almeida ***@***.***> wrote: I don't really remember, but I'm almost certain that I didn't. Yes, it's possible. I can't start the node right, get the following and lnd shutsdown 2018-05-07 20:33:53.346 [ERR] UTXN: Failed to sweep 1 kindergarten outputs at height=521658: Transaction rejected: output already spent 2018-05-07 20:33:53.347 [ERR] UTXN: Failed to graduate outputs at height=521658: Transaction rejected: output already spent 2018-05-07 20:35:05.421 [INF] NTFN: Cancelling epoch notification, epoch_id=2 2018-05-07 20:35:05.422 [ERR] SRVR: unable to start server: Transaction rejected: output already spent Transaction rejected: output already spent I don't have multiple nodes running on the same seed/state. — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#1194 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AA87LsoHAbEPKML4TE9LIzdnnK0lR_usks5twLBjgaJpZM4T0xIF> .

[Roasbeef]

What hardware were you running on?

[joaodealmeida]

It's on the first post. DO debian vps

[Roasbeef]

If you didn't modify the on-disk state manually at all, then perhaps it's possible that the VPS attempted some failed rollback/snapshot of the on disk state?

[joaodealmeida]

Fortunately I had moved wallet my wallet funds before. These 2 channels with bitrefill were the only channels I had local balance at. I'll try to reach justin.