Lightning: Daemon crash -> new_htlc_out:Input cltv_expiry 0 less than 549694?

[jarret]

Woke up to find my v0.6.2 node crashed. The crash.log is at https://gist.github.com/jarret/b5991325c8fc990b3350730e1ba5d53a

The crash output at the tail of the log is:

+443692.129672985 lightningd(24933):DEBUG: lightning_channeld-02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b chan #9: ... , awaiting 1122 +443692.129965521 lightning_gossipd(24943):DEBUG: REPLY WIRE_GOSSIP_GET_CHANNEL_PEER_REPLY with 0 fds +443692.147243956 lightningd(24933):BROKEN: new_htlc_out:Input cltv_expiry 0 less than 549694? +443692.264487684 lightningd(24933):BROKEN: FATAL SIGNAL 6 (version v0.6.2) +443692.264643332 lightningd(24933):BROKEN: backtrace: common/daemon.c:42 (crashdump) 0x4344c0 +443692.264795185 lightningd(24933):BROKEN: backtrace: (null):0 ((null)) 0x7f7d9728f4af +443692.264939689 lightningd(24933):BROKEN: backtrace: (null):0 ((null)) 0x7f7d9728f428 +443692.265083624 lightningd(24933):BROKEN: backtrace: (null):0 ((null)) 0x7f7d97291029 +443692.265226567 lightningd(24933):BROKEN: backtrace: lightningd/log.c:614 (fatal) 0x419c49 +443692.265372651 lightningd(24933):BROKEN: backtrace: lightningd/htlc_end.c:70 (corrupt) 0x40fa09 +443692.265519436 lightningd(24933):BROKEN: backtrace: lightningd/htlc_end.c:155 (htlc_out_check) 0x40ff0b +443692.265667551 lightningd(24933):BROKEN: backtrace: lightningd/htlc_end.c:269 (new_htlc_out) 0x4104a2 +443692.265819044 lightningd(24933):BROKEN: backtrace: lightningd/peer_htlcs.c:453 (send_htlc_out) 0x429bf5 +443692.265976030 lightningd(24933):BROKEN: backtrace: lightningd/peer_htlcs.c:548 (forward_htlc) 0x429f35 +443692.266121393 lightningd(24933):BROKEN: backtrace: lightningd/peer_htlcs.c:586 (channel_resolve_reply) 0x42a038 +443692.266269269 lightningd(24933):BROKEN: backtrace: lightningd/subd.c:282 (sd_msg_reply) 0x42e601 +443692.266414735 lightningd(24933):BROKEN: backtrace: lightningd/subd.c:421 (sd_msg_read) 0x42eb5c +443692.266582821 lightningd(24933):BROKEN: backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x46a828 +443692.266730852 lightningd(24933):BROKEN: backtrace: ccan/ccan/io/io.c:395 (do_plan) 0x46b31d +443692.266875203 lightningd(24933):BROKEN: backtrace: ccan/ccan/io/io.c:405 (io_ready) 0x46b35b +443692.267019127 lightningd(24933):BROKEN: backtrace: ccan/ccan/io/poll.c:310 (io_loop) 0x46cebb +443692.267158502 lightningd(24933):BROKEN: backtrace: lightningd/lightningd.c:745 (main) 0x417e40 +443692.267221181 lightningd(24933):BROKEN: backtrace: (null):0 ((null)) 0x7f7d9727a82f +443692.267231821 lightningd(24933):BROKEN: backtrace: (null):0 ((null)) 0x403618 +443692.267239389 lightningd(24933):BROKEN: backtrace: (null):0 ((null)) 0xffffffffffffffff

This is the same node/getinfo as in #2069, with id 02e389d861acd9d6f5700c99c6c33dd4460d6f1e2f6ba89d1f4f36be85fc60f8d7 It is connected through a half-dozen or so channels to other nodes operated by other parties.

[kallerosenbaum]

I second this bug. But while reporting I managed to nuke the crashlog brilliantly by cat crash.log.20181114085800 |gzip>crash.log.20181114085800. Sorry. I'm on v0.6.2 too.

[jarret]

I have hit this crash a couple more times - seems to come every day or three on my node.

[thorie7912]

Same here https://github.com/ElementsProject/lightning/issues/2142

[ctrlbreak-]

Ditto...

+169078.705882862 lightningd(15920):BROKEN: new_htlc_out:Input cltv_expiry 0 less than 556898?
+169078.729013157 lightningd(15920):BROKEN: FATAL SIGNAL 6 (version v0.6.2-51-gd5aaa11)
+169078.729089448 lightningd(15920):BROKEN: backtrace: common/daemon.c:43 (crashdump) 0x437c55
+169078.729127228 lightningd(15920):BROKEN: backtrace: (null):0 ((null)) 0x7f53eb6174af
+169078.729153767 lightningd(15920):BROKEN: backtrace: (null):0 ((null)) 0x7f53eb617428
+169078.729186965 lightningd(15920):BROKEN: backtrace: (null):0 ((null)) 0x7f53eb619029
+169078.729209632 lightningd(15920):BROKEN: backtrace: lightningd/log.c:614 (fatal) 0x41a860
+169078.729235746 lightningd(15920):BROKEN: backtrace: lightningd/htlc_end.c:70 (corrupt) 0x4102de
+169078.729351298 lightningd(15920):BROKEN: backtrace: lightningd/htlc_end.c:155 (htlc_out_check) 0x4107e0
+169078.729388719 lightningd(15920):BROKEN: backtrace: lightningd/htlc_end.c:269 (new_htlc_out) 0x410d77
+169078.729424427 lightningd(15920):BROKEN: backtrace: lightningd/peer_htlcs.c:453 (send_htlc_out) 0x42b73d
+169078.729450010 lightningd(15920):BROKEN: backtrace: lightningd/peer_htlcs.c:548 (forward_htlc) 0x42ba7d
+169078.729472310 lightningd(15920):BROKEN: backtrace: lightningd/peer_htlcs.c:586 (channel_resolve_reply) 0x42bb80
+169078.729507057 lightningd(15920):BROKEN: backtrace: lightningd/subd.c:282 (sd_msg_reply) 0x431540
+169078.729541861 lightningd(15920):BROKEN: backtrace: lightningd/subd.c:421 (sd_msg_read) 0x431ad5
+169078.729578817 lightningd(15920):BROKEN: backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x46f02a
+169078.729612674 lightningd(15920):BROKEN: backtrace: ccan/ccan/io/io.c:395 (do_plan) 0x46fb1f
+169078.729647200 lightningd(15920):BROKEN: backtrace: ccan/ccan/io/io.c:405 (io_ready) 0x46fb5d
+169078.729742679 lightningd(15920):BROKEN: backtrace: ccan/ccan/io/poll.c:310 (io_loop) 0x4716bd
+169078.729778233 lightningd(15920):BROKEN: backtrace: lightningd/lightningd.c:769 (main) 0x418a65
+169078.729813598 lightningd(15920):BROKEN: backtrace: (null):0 ((null)) 0x7f53eb60282f
+169078.729846293 lightningd(15920):BROKEN: backtrace: (null):0 ((null)) 0x403718
+169078.729892197 lightningd(15920):BROKEN: backtrace: (null):0 ((null)) 0xffffffffffffffff

[ctrlbreak-]

Ummm... my node has now crashed with this issue 4 times today

Every time this has occurred, it's been on the same channel with the same peer (a very very well connected peer). Anyone else seeing the same thing? Is this information helpful?

[jarret]

yeah, me too. It was quiet for a week or two, but I have restarted it several times _today_.

[ctrlbreak-]

jarret, Do you have DEBUG logging turned on? Can you tell if its all originating from the same common node (FYI, mine was a channel to 02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b)

[jarret]

Yes, I have logs. Your suspicion is confirmed. It is 02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b
my debug log from my most recent crash is here: https://gist.github.com/jarret/adf2b3a45288c4e6a4713af54f4e1202

[rustyrussell]

Thanks, I think I found it. I've pushed a test fix based on 0.6.2 to my minimal-fix branch, but the change is trivial if you wouldn't mind testing:

In lightningd/peer_htlcs.c line 201, change:

if (cltv_expiry - delta >= outgoing_cltv_value)

To insert delta < cltv_expiry && like so:

if (delta < cltv_expiry && cltv_expiry - delta >= outgoing_cltv_value)

Then make && make install, and restart lightningd.

Meanwhile I've opened a channel to rompert.com to see if I can get it to happen to my node, too...

[jarret]

Sweet! I have the patch compiled and running on my node that has been crashing. Should be able to leave it running for as long as necessary.

[robtex]

hi peeps. haven't kept up with lightning lately, my nodes are on autopilot and autobalancer and i suspect the latter might cause these issues in some way.
for whatever it helps, it looks a bit similar like this one https://github.com/lightningnetwork/lnd/issues/1664
sorry about the inconvenience

[gallizoltan]

I've seen this crash a few times today. Thanks for the fix!

[ctrlbreak-]

Well, it would appear Rompert re-established a channel to my node and then traffic from him subsequently crashed it overnight again. I haven't killed his new channel, and I've recompiled latest master. Lets see what happens :-/

[gallizoltan]

This fix seems to be good for me.
Before this, my node crashed six times yesterday, according to logs. But since this fix, not a single crash! Thank you very much!

[jarret]

Same here. Since running the patch I have not experienced any more crashes. I haven't touched my channel with 02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b and everything seems fine.

[cdecker]

Thanks everybody for confirming. Please let us know if the problem reappears, but I'm hopeful that @rustyrussell's fix did the trick.