[ERR] SRVR: unable to start server: -26: 16: bad-txns-vout-empty

[yuilleb]

Background

2018-04-03 03:02:02.704 [INF] CNCT: ChannelArbitrator(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0): starting state=StateBroadcastCommit
2018-04-03 03:02:02.705 [INF] CNCT: ChannelArbitrator(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0): force closing chan
2018-04-03 03:02:02.721 [INF] HSWC: Removing channel link with ChannelID(410a082789b457e13332ced94ef6603a19089f394e9a8bbb3f24885345eb235b)
2018-04-03 03:02:02.721 [ERR] CNCT: unable to mark link inactive: channel link not found
2018-04-03 03:02:02.724 [INF] CNCT: Broadcasting force close transaction, ChannelPoint(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0): (*wire.MsgTx)(0xc420847900)({
 Version: (int32) 2,
 TxIn: ([]*wire.TxIn) (len=1 cap=1) {
  (*wire.TxIn)(0xc420210b40)({
   PreviousOutPoint: (wire.OutPoint) 5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0,
   SignatureScript: ([]uint8) {
   },
   Witness: (wire.TxWitness) (len=4 cap=4) {
    ([]uint8) <nil>,
    ([]uint8) (len=71 cap=144) {
     00000000  30 44 02 20 11 47 b1 58  7f 1b fa 4f 9f a6 2b f0  |0D. .G.X...O..+.|
     00000010  48 3c 9c a9 4c 5e 46 d2  b2 e9 48 08 5d 61 e8 5d  |H<..L^F...H.]a.]|
     00000020  78 db 02 87 02 20 16 fd  84 81 16 b9 9d 0e 50 e9  |x.... ........P.|
     00000030  93 90 e3 87 2f 0e ac 2e  7b 0f 20 3b c6 25 d0 d8  |..../...{. ;.%..|
     00000040  d9 0e 5c be 93 93 01                              |..\....|
    },
    ([]uint8) (len=72 cap=144) {
     00000000  30 45 02 21 00 8d a9 f5  84 ff e7 2e 28 18 4c ef  |0E.!........(.L.|
     00000010  0a 4d 21 fe 1f 89 0c 7c  eb b5 0b ee c1 a8 d6 88  |.M!....|........|
     00000020  22 1f 19 66 99 02 20 6e  33 92 65 06 a0 26 5c f8  |"..f.. n3.e..&\.|
     00000030  ce 59 2e 04 fd bd 96 e8  ad 72 9f be 4f d8 e4 7b  |.Y.......r..O..{|
     00000040  00 12 9f 63 7c 50 a8 01                           |...c|P..|
    },
    ([]uint8) (len=71 cap=500) {
     00000000  52 21 03 df be 43 7d 17  dc 4c 7a 4d ea 9f 4d 55  |R!...C}..LzM..MU|
     00000010  17 c7 9d 70 f5 d5 6b cd  02 39 57 72 bd 49 69 96  |...p..k..9Wr.Ii.|
     00000020  90 96 30 21 03 e6 98 57  fe 49 12 75 38 6f 96 95  |..0!...W.I.u8o..|
     00000030  2a f8 9c 96 cc ef 07 ca  52 a8 ff 3f 2e 26 ce b8  |*.......R..?.&..|
     00000040  86 df 0d c8 24 52 ae                              |....$R.|
    }
   },
   Sequence: (uint32) 2150939238
  })
 },
 TxOut: ([]*wire.TxOut) {
 },
 LockTime: (uint32) 543351913
})

2018-04-03 03:02:02.734 [ERR] CNCT: ChannelArbitrator(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0): unable to broadcast close tx: -26: 16: bad-txns-vout-empty
2018-04-03 03:02:02.734 [ERR] CNCT: unable to advance state: -26: 16: bad-txns-vout-empty
2018-04-03 03:02:02.734 [ERR] SRVR: unable to start server: -26: 16: bad-txns-vout-empty

-26: 16: bad-txns-vout-empty

Your environment

• lnd version 0.4.1-beta commit=6fa93a78c18180a3bc77116b749b3c5e279d5a33
• Linux 3.16.0-5-amd64 Fix name typo in README #1 SMP Debian 3.16.51-3+deb8u1 (2018-01-08) x86_64 GNU/Linux
• Bitcoin Core Daemon version v0.16.0

Steps to reproduce

This channel was flapping from start to stop in the previous version. I upgraded lnd expecting the problem to be fix as stated in an issue that I found on here. Now lnd won't start at all. I tried going back to 0.4.0, but that version exits with the same error as well now.

[yuilleb]

Any idea how to fix this so I can run lnd again?

[Roasbeef]

Duplicate of #975. Checks in the latest version of lnd have been added to ensure this can never happend. If you apply this (temporary) patch, then you'll be able to boot up again: #975 (comment)

[yuilleb]

Thanks. I'm back up and running though the offending channel is still flapping up and down. Any way to prevent this?

2018-04-05 20:57:05.816 [INF] NTFN: New block epoch subscription
2018-04-05 20:57:05.817 [INF] HSWC: ChannelLink(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0) is starting
2018-04-05 20:57:05.818 [INF] HSWC: Added channel link with chan_id=410a082789b457e13332ced94ef6603a19089f394e9a8bbb3f24885345eb235b, short_chan_id=((lnwire.ShortChannelID) 515439:2052:0
)
2018-04-05 20:57:05.818 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0)
2018-04-05 20:57:05.818 [INF] HSWC: HTLC manager for ChannelPoint(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0) started, bandwidth=0 mSAT
2018-04-05 20:57:05.818 [INF] HSWC: Trimming open circuits for chan_id=515439:2052:0, start_htlc_id=0
2018-04-05 20:57:05.818 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0)
2018-04-05 20:57:05.879 [INF] DISC: Syncing channel graph state with 027fe40fda644dbbce9b51fc7cff5809586d02bfc7c308d54a80002989c14f40de, sending 8690 vertexes and 4359 edges
2018-04-05 20:57:05.879 [INF] SRVR: Attempting to send msgs 21744 to: 027fe40fda644dbbce9b51fc7cff5809586d02bfc7c308d54a80002989c14f40de
2018-04-05 20:57:06.503 [INF] HSWC: Received re-establishment message from remote side for channel(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0)
2018-04-05 20:57:06.627 [ERR] HSWC: ChannelPoint(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0): unable to accept new commitment: commitment transaction dips peer below chan reserve
2018-04-05 20:57:06.627 [INF] PEER: unable to read message from 173.249.28.20:56090: read tcp 10.33.1.6:9735->173.249.28.20:56090: use of closed network connection
2018-04-05 20:57:06.627 [INF] HSWC: Removing channel link with ChannelID(410a082789b457e13332ced94ef6603a19089f394e9a8bbb3f24885345eb235b)
2018-04-05 20:57:06.628 [INF] HSWC: ChannelLink(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0) is stopping
2018-04-05 20:57:06.628 [INF] NTFN: Cancelling epoch notification, epoch_id=1515
2018-04-05 20:57:06.628 [INF] HSWC: ChannelLink(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0) has exited
2018-04-05 20:57:07.408 [INF] SRVR: New inbound connection from 173.249.28.20:56096
2018-04-05 20:57:07.542 [INF] PEER: NodeKey(027fe40fda644dbbce9b51fc7cff5809586d02bfc7c308d54a80002989c14f40de) loading ChannelPoint(5b23eb455388243fbb8b9a4e399f08193a60f64ed9ce3233e157b48927080a41:0)

[Roasbeef]

Nice! I'd simply use iptables to ban that IP for now. Unfortunately, the channel is in a state that can't properly be closed, but it was the remote party that put up all the funds. The issue was that the channel was so small, that a fee update consumed all the funds to miner's fees.

[yuilleb]

Ahh ok that makes a lot of sense. Thanks for your help and great job with all your work!

[Roasbeef]

Thanks! Resolving this for now as it isn't possible to enter this state on the newest version of lnd.