Lnd: Funds lost after counterparty force-closed channel

[zyp]

I was cleaning up a set of three testnet lnd docker instances that I used for some tests last weekend, closing the channels and recycling the funds back to a normal wallet. The containers were built from revision 607b394.

For the channel between nodes A and B, I sent all funds to the B side of the channel before closing it. The channel wouldn't close properly, so I did a force close on node A. Node B didn't seem to pick this up, so I restarted it. After node B was restarted, neither the channel nor the funds shows up anywhere in listchannels, pendingchannels, walletbalance, channelbalance or listchaintxns.

Here is the log from B after restarting it. Unfortunately I didn't keep the earlier logs. This seems to indicate what happened though:

2018-01-12 21:12:55.344 [INF] BRAR: Sweeping breached outputs with: (*wire.MsgTx)(0xc420274b40)({
 Version: (int32) 2,
 TxIn: ([]*wire.TxIn) (len=1 cap=15) {
  (*wire.TxIn)(0xc4202ec9c0)({
   PreviousOutPoint: (wire.OutPoint) 1b9ecf133ee201b08d7e23b92e98acd6924ccfe7b60fc3ed1b3fbc80ae5c5448:0,
   SignatureScript: ([]uint8) <nil>,
   Witness: (wire.TxWitness) (len=2 cap=2) {
    ([]uint8) (len=71 cap=144) {
     00000000  30 44 02 20 52 7e bb d3  45 47 cd 02 71 1a 98 23  |0D. R~..EG..q..#|
     00000010  b5 4e a8 f1 db 0d c3 46  78 f0 fc cd db ea 67 b7  |.N.....Fx.....g.|
     00000020  c1 ee ec fb 02 20 16 48  75 c1 b1 6b a0 b4 31 84  |..... .Hu..k..1.|
     00000030  96 d3 b8 d2 d5 41 de f0  37 89 5f 3b 4e f5 ad a2  |.....A..7._;N...|
     00000040  a8 29 33 92 aa d5 01                              |.)3....|
    },
    ([]uint8) (len=33 cap=33) {
     00000000  02 23 4c 14 cb 7c 3c 2b  af 81 66 8b 9f fd cb 62  |.#L..|<+..f....b|
     00000010  92 32 98 8d 77 15 3e 73  28 26 a7 9e 0f f1 d8 2d  |.2..w.>s(&.....-|
     00000020  8c                                                |.|
    }
   },
   Sequence: (uint32) 0
  })
 },
 TxOut: ([]*wire.TxOut) (len=1 cap=15) {
  (*wire.TxOut)(0xc42068c640)({
   Value: (int64) 9998934,
   PkScript: ([]uint8) (len=22 cap=500) {
    00000000  00 14 02 88 57 42 99 fd  62 a2 0b 85 32 fb cc 07  |....WB..b...2...|
    00000010  85 70 4c c3 b9 d2                                 |.pL...|
   }
  })
 },
 LockTime: (uint32) 0
})

2018-01-12 21:12:55.349 [ERR] BRAR: unable to broadcast tx: -22: TX rejected: total value of all transaction inputs for transaction 5792339c06d0769dd977430ea993ba46d494b55191795039e511bff53f9849c0 is 9997104 which is less than the amount spent of 9998934
2018-01-12 21:12:55.349 [INF] BRAR: Force closed ChannelPoint(ecd0fb5e72e33d64b446a2492eec6a3dff99650c5a3c2e36405f7592d27a9daf:0) is fully closed, updating DB

What I read from this: Node B detected the closing transaction, then tried to sweep the funds from it. The sweeping transaction got rejected due to the amount being valid, but lnd still considers the channel fully closed and forgets it.

The end result is that the funds are still stuck on the 1b9ecf1… output and lnd has given up trying to recover them.

As for why the amount in the sweeping transaction is invalid, I think it tried to subtract a negative fee from it. The errors I got when trying to do a mutual close earlier seemed to be related.

[whereyouatwimm]

Did you run this cluster using the --simnet? You might need to mine a block after closing the channel.

$btcctl --simnet --rpcuser=kek --rpcpass=kek generate 1

[zyp]

No, as I stated, the nodes were running on testnet. Had they been running on simnet, I wouldn't have bothered recycling the funds before deleting the instances.

[Roasbeef]

Looks like the culprit is an arithmetic error when computing the total value of the inputs. Do you have logs of the cooperative closure attempt that didn't quite succeed?

I think I have a pretty good idea of what happened. Generally we need to logically centralize all handling+dispatching of on-chain events into a single sub-system. Things are a bit sprawled atm, opening up the possibility of bugs like this where the sub-systems notion of the current state of the channel is skewed due to blinding introduced by a bug (right now closeObservers are linked to the lifetime of an active channel object in memory, instead they should be persistent and have their own separate lifetime).

I'm nearly done with the initial infrastructure to set up this isolated sub-system for dispatching on-chain events. Once this is complete, bugs like this should be a thing of the past. Should be landing early this coming week!

[Roasbeef]

This now be fixed in the latest master as a result of the architectural changes with the breach arbiter, and also the new feature of the contractcourt pckage.