lightningd keeps crashing with FATAL SIGNAL 6 RECEIVED #1308

robtex · 2018-04-01T12:25:36Z

Issue and Steps to Reproduce

2018-04-01T05:28:42.394Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: peer_out WIRE_SHUTDOWN             
2018-04-01T05:28:42.394Z lightning_gossipd(1167): Received channel_update for channel 515454:1348:0(1) now ACTIVE                                                              
2018-04-01T05:28:42.394Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: UPDATE WIRE_CHANNEL_SHUTDOWN_COMPLETE                                                                                                                                                                             2018-04-01T05:28:42.394Z lightning_gossipd(1167): Received channel_update for channel 515419:1416:0(0) now ACTIVE                                                             
2018-04-01T05:28:42.394Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: UPDATE WIRE_CHANNEL_SHUTDOWN_COMPLETE                                                                                                                                                                             2018-04-01T05:28:42.410Z lightningd(1159): lightning_closingd-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: pid 17724, msgfd 19                
2018-04-01T05:28:42.426Z lightningd(1159): 027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: State changed from CHANNELD_AWAITING_LOCKIN to CLOSINGD_SIGEXCHANGE
2018-04-01T05:28:42.426Z lightningd(1159): channel state CHANNELD_AWAITING_LOCKIN should be CHANNELD_SHUTTING_DOWN
2018-04-01T05:28:42.426Z lightningd(1159): FATAL SIGNAL 6 RECEIVED
2018-04-01T05:28:42.470Z lightningd(1159): backtrace: lightningd/log.c:494 (log_crash) 0x415f89
2018-04-01T05:28:42.470Z lightningd(1159): backtrace: (null):0 ((null)) 0x7fdb982e24af
2018-04-01T05:28:42.470Z lightningd(1159): backtrace: (null):0 ((null)) 0x7fdb982e2428
2018-04-01T05:28:42.470Z lightningd(1159): backtrace: (null):0 ((null)) 0x7fdb982e4029
2018-04-01T05:28:42.470Z lightningd(1159): backtrace: lightningd/log.c:592 (fatal) 0x4163da
2018-04-01T05:28:42.471Z lightningd(1159): backtrace: lightningd/channel.c:276 (channel_set_state) 0x409115
2018-04-01T05:28:42.471Z lightningd(1159): backtrace: lightningd/channel_control.c:106 (peer_start_closingd_after_shutdown) 0x409b4c
2018-04-01T05:28:42.471Z lightningd(1159): backtrace: lightningd/channel_control.c:137 (channel_msg) 0x409d28
2018-04-01T05:28:42.471Z lightningd(1159): backtrace: lightningd/subd.c:504 (sd_msg_read) 0x42b9c7
2018-04-01T05:28:42.472Z lightningd(1159): backtrace: lightningd/subd.c:330 (read_fds) 0x42b2dc
2018-04-01T05:28:42.472Z lightningd(1159): backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x4644b0
2018-04-01T05:28:42.472Z lightningd(1159): backtrace: ccan/ccan/io/io.c:387 (do_plan) 0x464f87
2018-04-01T05:28:42.472Z lightningd(1159): backtrace: ccan/ccan/io/io.c:397 (io_ready) 0x464fc5
2018-04-01T05:28:42.472Z lightningd(1159): backtrace: ccan/ccan/io/poll.c:310 (io_loop) 0x46690f
2018-04-01T05:28:42.473Z lightningd(1159): backtrace: lightningd/lightningd.c:407 (main) 0x414739
2018-04-01T05:28:42.473Z lightningd(1159): backtrace: (null):0 ((null)) 0x7fdb982cd82f
2018-04-01T05:28:42.473Z lightningd(1159): backtrace: (null):0 ((null)) 0x403448
2018-04-01T05:28:42.473Z lightningd(1159): backtrace: (null):0 ((null)) 0xffffffffffffffff

`getinfo` output

{ "id" : "024bd94f0425590434538fd21d4e58982f7e9cfd8f339205a73deb9c0e0341f5bd", "port" : 9735, "address" :
        [
                { "type" : "ipv4", "address" : "165.227.69.151", "port" : 9735 },
                { "type" : "ipv6", "address" : "2604:a880:800:a1::cbb:f001", "port" : 9735 } ], "version" : "v0.5.2-2016-11-21-2448-ge41d565", "blockheight" : 456652, "network" : "bitcoin" }

The text was updated successfully, but these errors were encountered:

cdecker · 2018-04-01T14:36:17Z

Assigned this to our resident state machine expert @rustyrussell, I think it should be safe to just allow the state transition. Then again, I can't come up with a valid transition from CHANNELD_SHUTTING_DOWN -> CHANNELD_AWAITING_LOCKIN, did you restart the client while it was shutting down?

Could you provide more logs?

robtex · 2018-04-01T15:45:33Z

thanks.
no i'm afraid i just leave the lightningd to terminate at it's own will. i don't operate on that node until it has synced all blocks. i just leave it alone.
i have a while-loop that restarts lightningd when it stops, after archiving the last log.
now and then i git pull so next time it restarts i have a fresher lightningd, but i never manually stop or start it.
more logs? you can get a few others from previous crashes but they all look pretty much the same.
if i can enable more detailed logging or whatever could help, let me know how.
it does throw out a bunch of the lightning_channeld: Writing out status 65520: Broken pipe on STDERR, but not sure when that happens.

robtex · 2018-04-01T15:47:07Z

three latest crashes (including the one previously posted)

2018-03-31T19:38:06.209Z lightningd(30078): lightning_channeld-03ad7fe66e7b95e9db50696488a029315cd0e22b7cd36d344eb53e52742abfced6 chan #853: Peer connection lost
2018-03-31T19:38:06.209Z lightningd(30078): 03ad7fe66e7b95e9db50696488a029315cd0e22b7cd36d344eb53e52742abfced6 chan #853: Peer transient failure in CHANNELD_AWAITING_LOCKIN: lightning_channeld: Owning subdaemon lightning_channeld died (62208)
2018-03-31T19:38:06.209Z lightningd(30078): lightning_channeld-036c977839833af6b6994ee2c9a7155ad8c256a114378bb3718c3cfa24384c867d chan #939: Can't send commit: nothing to send
2018-03-31T19:38:06.209Z lightningd(30078): lightning_channeld-03b1be68b8f564fe53f5456cf4bec901ba968fb72ed7291279ab0c87e0d22f1f49 chan #732: Peer connection lost
2018-03-31T19:38:06.209Z lightningd(30078): 03b1be68b8f564fe53f5456cf4bec901ba968fb72ed7291279ab0c87e0d22f1f49 chan #732: Peer transient failure in CHANNELD_AWAITING_LOCKIN: lightning_channeld: Owning subdaemon lightning_channeld died (62208)
2018-03-31T19:38:06.210Z lightningd(30078): lightning_channeld-02262bbc21c171bc91a1d6bbf89571c95873849b9a60d3ea9671b777d852d39ecd chan #720: Peer connection lost              2018-03-31T19:38:06.210Z lightningd(30078): 02262bbc21c171bc91a1d6bbf89571c95873849b9a60d3ea9671b777d852d39ecd chan #720: Peer transient failure in CHANNELD_AWAITING_LOCKIN: lightning_channeld: Owning subdaemon lightning_channeld died (62208)
2018-03-31T19:38:06.210Z lightning_gossipd(30086): UPDATE WIRE_GOSSIP_PEER_CONNECTED
2018-03-31T19:38:06.211Z lightningd(30078): 02da0713ab1b12eeb01f212944a435077f39f1b767ee5c24b01cdb4b0b9377b66b chan #815: Peer has reconnected, state CHANNELD_NORMAL          2018-03-31T19:38:06.211Z lightningd(30078): Client: Received message 1 from client                                                                                             2018-03-31T19:38:06.211Z lightningd(30078): Client: Received message 3 from client
2018-03-31T19:38:06.211Z lightningd(30078): Client: Received message 3 from client
2018-03-31T19:38:06.215Z lightningd(30078): Client: Received message 9 from client
2018-03-31T19:38:06.219Z lightningd(30078): lightning_channeld-02da0713ab1b12eeb01f212944a435077f39f1b767ee5c24b01cdb4b0b9377b66b chan #815: pid 28822, msgfd 43
2018-03-31T19:38:06.219Z lightningd(30078): 02da0713ab1b12eeb01f212944a435077f39f1b767ee5c24b01cdb4b0b9377b66b chan #815: Already have funding locked in
2018-03-31T19:38:06.230Z lightning_gossipd(30086): Received channel_update for channel 515798:1597:0(1) now ACTIVE                                                             2018-03-31T19:38:06.231Z lightningd(30078): lightning_channeld-036c977839833af6b6994ee2c9a7155ad8c256a114378bb3718c3cfa24384c867d chan #939: peer_out WIRE_SHUTDOWN
2018-03-31T19:38:06.231Z lightning_gossipd(30086): Received channel_update for channel 515657:1534:0(0) now ACTIVE
2018-03-31T19:38:06.231Z lightningd(30078): lightning_channeld-036c977839833af6b6994ee2c9a7155ad8c256a114378bb3718c3cfa24384c867d chan #939: UPDATE WIRE_CHANNEL_SHUTDOWN_COMPLETE
2018-03-31T19:38:06.231Z lightning_gossipd(30086): Received channel_update for channel 515647:1148:0(1) now ACTIVE
2018-03-31T19:38:06.232Z lightningd(30078): lightning_channeld-036c977839833af6b6994ee2c9a7155ad8c256a114378bb3718c3cfa24384c867d chan #939: UPDATE WIRE_CHANNEL_SHUTDOWN_COMPLETE
2018-03-31T19:38:06.267Z lightningd(30078): lightning_closingd-036c977839833af6b6994ee2c9a7155ad8c256a114378bb3718c3cfa24384c867d chan #939: pid 28823, msgfd 19               2018-03-31T19:38:06.268Z lightningd(30078): 036c977839833af6b6994ee2c9a7155ad8c256a114378bb3718c3cfa24384c867d chan #939: State changed from CHANNELD_AWAITING_LOCKIN to CLOSINGD_SIGEXCHANGE
2018-03-31T19:38:06.268Z lightningd(30078): channel state CHANNELD_AWAITING_LOCKIN should be CHANNELD_SHUTTING_DOWN                                                            2018-03-31T19:38:06.268Z lightningd(30078): FATAL SIGNAL 6 RECEIVED
2018-03-31T19:38:06.303Z lightningd(30078): backtrace: lightningd/log.c:494 (log_crash) 0x415f89
2018-03-31T19:38:06.303Z lightningd(30078): backtrace: (null):0 ((null)) 0x7fd9bdd304af                                                                                        2018-03-31T19:38:06.303Z lightningd(30078): backtrace: (null):0 ((null)) 0x7fd9bdd30428                                                                                        2018-03-31T19:38:06.303Z lightningd(30078): backtrace: (null):0 ((null)) 0x7fd9bdd32029
2018-03-31T19:38:06.303Z lightningd(30078): backtrace: lightningd/log.c:592 (fatal) 0x4163da
2018-03-31T19:38:06.303Z lightningd(30078): backtrace: lightningd/channel.c:276 (channel_set_state) 0x409115                                                                   2018-03-31T19:38:06.303Z lightningd(30078): backtrace: lightningd/channel_control.c:106 (peer_start_closingd_after_shutdown) 0x409b4c                                          2018-03-31T19:38:06.304Z lightningd(30078): backtrace: lightningd/channel_control.c:137 (channel_msg) 0x409d28                                                                 2018-03-31T19:38:06.313Z lightningd(30078): backtrace: lightningd/subd.c:504 (sd_msg_read) 0x42b9c7
2018-03-31T19:38:06.314Z lightningd(30078): backtrace: lightningd/subd.c:330 (read_fds) 0x42b2dc
2018-03-31T19:38:06.314Z lightningd(30078): backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x4644b0
2018-03-31T19:38:06.314Z lightningd(30078): backtrace: ccan/ccan/io/io.c:387 (do_plan) 0x464f87                                                                                2018-03-31T19:38:06.314Z lightningd(30078): backtrace: ccan/ccan/io/io.c:397 (io_ready) 0x464fc5
2018-03-31T19:38:06.314Z lightningd(30078): backtrace: ccan/ccan/io/poll.c:310 (io_loop) 0x46690f
2018-03-31T19:38:06.314Z lightningd(30078): backtrace: lightningd/lightningd.c:407 (main) 0x414739
2018-03-31T19:38:06.314Z lightningd(30078): backtrace: (null):0 ((null)) 0x7fd9bdd1b82f
2018-03-31T19:38:06.314Z lightningd(30078): backtrace: (null):0 ((null)) 0x403448
2018-03-31T19:38:06.314Z lightningd(30078): backtrace: (null):0 ((null)) 0xffffffffffffffff

2018-04-01T04:08:53.268Z lightningd(28833): 02da0713ab1b12eeb01f212944a435077f39f1b767ee5c24b01cdb4b0b9377b66b chan #815: Peer transient failure in CHANNELD_NORMAL: lightning_channeld: Owning subdaemon lightning_channeld died (62208)
2018-04-01T04:08:53.272Z lightning_gossipd(28841): req: type WIRE_GOSSIPCTL_REACH_PEER len 35
2018-04-01T04:08:53.284Z lightningd(28833): bitcoin-cli -datadir=/big/btc0 gettxout c952d7969e7837e24662d014c99eb5182399c145fb31752d1325a8d6e66950fb 1: not unspent output?
2018-04-01T04:08:53.308Z lightning_gossipd(28841): Connected out for 02da0713ab1b12eeb01f212944a435077f39f1b767ee5c24b01cdb4b0b9377b66b                                        2018-04-01T04:08:53.330Z lightning_gossipd(28841): req: type WIRE_GOSSIP_GET_TXOUT_REPLY len 20
2018-04-01T04:08:53.330Z lightning_gossipd(28841): channel_announcement: no unspent txout 515620:2329:1                                                                        2018-04-01T04:08:53.343Z lightning_gossipd(28841): peer_out WIRE_INIT                                                                                                          2018-04-01T04:08:53.374Z lightning_gossipd(28841): peer_in WIRE_INIT
2018-04-01T04:08:53.374Z lightning_gossipd(28841): UPDATE WIRE_GOSSIP_PEER_CONNECTED
2018-04-01T04:08:53.374Z lightning_gossipd(28841): UPDATE WIRE_GOSSIP_PEER_CONNECTED                                                                                           2018-04-01T04:08:53.374Z lightningd(28833): 02da0713ab1b12eeb01f212944a435077f39f1b767ee5c24b01cdb4b0b9377b66b chan #815: Peer has reconnected, state CHANNELD_NORMAL          2018-04-01T04:08:53.374Z lightningd(28833): Client: Received message 1 from client
2018-04-01T04:08:53.375Z lightningd(28833): Client: Received message 9 from client
2018-04-01T04:08:53.396Z lightningd(28833): lightning_channeld-02da0713ab1b12eeb01f212944a435077f39f1b767ee5c24b01cdb4b0b9377b66b chan #815: pid 1148, msgfd 126
2018-04-01T04:08:53.396Z lightningd(28833): 02da0713ab1b12eeb01f212944a435077f39f1b767ee5c24b01cdb4b0b9377b66b chan #815: Already have funding locked in
2018-04-01T04:08:53.514Z lightningd(28833): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: peer_in WIRE_SHUTDOWN
2018-04-01T04:08:53.522Z lightningd(28833): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: UPDATE WIRE_CHANNEL_GOT_SHUTDOWN  2018-04-01T04:08:53.557Z lightningd(28833): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: Trying commit
2018-04-01T04:08:53.557Z lightningd(28833): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: Can't send commit: nothing to send
2018-04-01T04:08:53.558Z lightningd(28833): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: peer_out WIRE_SHUTDOWN            2018-04-01T04:08:53.558Z lightningd(28833): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: UPDATE WIRE_CHANNEL_SHUTDOWN_COMPLETE
2018-04-01T04:08:53.558Z lightningd(28833): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: UPDATE WIRE_CHANNEL_SHUTDOWN_COMPLETE
2018-04-01T04:08:53.592Z lightningd(28833): lightning_closingd-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: pid 1149, msgfd 19                2018-04-01T04:08:53.594Z lightningd(28833): 027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: State changed from CHANNELD_AWAITING_LOCKIN to CLOSINGD_SIGEXCHANGE
2018-04-01T04:08:53.605Z lightningd(28833): channel state CHANNELD_AWAITING_LOCKIN should be CHANNELD_SHUTTING_DOWN                                                            2018-04-01T04:08:53.605Z lightningd(28833): FATAL SIGNAL 6 RECEIVED
2018-04-01T04:08:53.726Z lightningd(28833): backtrace: lightningd/log.c:494 (log_crash) 0x415f89
2018-04-01T04:08:53.726Z lightningd(28833): backtrace: (null):0 ((null)) 0x7feb0aea64af                                                                                        2018-04-01T04:08:53.726Z lightningd(28833): backtrace: (null):0 ((null)) 0x7feb0aea6428                                                                                        2018-04-01T04:08:53.726Z lightningd(28833): backtrace: (null):0 ((null)) 0x7feb0aea8029
2018-04-01T04:08:53.726Z lightningd(28833): backtrace: lightningd/log.c:592 (fatal) 0x4163da
2018-04-01T04:08:53.726Z lightningd(28833): backtrace: lightningd/channel.c:276 (channel_set_state) 0x409115                                                                   2018-04-01T04:08:53.727Z lightningd(28833): backtrace: lightningd/channel_control.c:106 (peer_start_closingd_after_shutdown) 0x409b4c                                          2018-04-01T04:08:53.727Z lightningd(28833): backtrace: lightningd/channel_control.c:137 (channel_msg) 0x409d28                                                                 2018-04-01T04:08:53.729Z lightningd(28833): backtrace: lightningd/subd.c:504 (sd_msg_read) 0x42b9c7
2018-04-01T04:08:53.729Z lightningd(28833): backtrace: lightningd/subd.c:330 (read_fds) 0x42b2dc
2018-04-01T04:08:53.734Z lightningd(28833): backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x4644b0
2018-04-01T04:08:53.734Z lightningd(28833): backtrace: ccan/ccan/io/io.c:387 (do_plan) 0x464f87                                                                                2018-04-01T04:08:53.734Z lightningd(28833): backtrace: ccan/ccan/io/io.c:397 (io_ready) 0x464fc5
2018-04-01T04:08:53.734Z lightningd(28833): backtrace: ccan/ccan/io/poll.c:310 (io_loop) 0x46690f
2018-04-01T04:08:53.734Z lightningd(28833): backtrace: lightningd/lightningd.c:407 (main) 0x414739
2018-04-01T04:08:53.734Z lightningd(28833): backtrace: (null):0 ((null)) 0x7feb0ae9182f
2018-04-01T04:08:53.734Z lightningd(28833): backtrace: (null):0 ((null)) 0x403448
2018-04-01T04:08:53.734Z lightningd(28833): backtrace: (null):0 ((null)) 0xffffffffffffffff

2018-04-01T05:28:42.372Z lightningd(1159): lightning_channeld-03f8109578aae1e5cfc497e466cf6ae6625497cd31886e87b2f4f54f3f0f46b539 chan #710: Got ping, sending WIRE_PONG        2018-04-01T05:28:42.372Z lightningd(1159): lightning_channeld-0354d8382003663d8d825954224f80dcbd740b5031c5a588277a20c75586d41053 chan #733: Got ping, sending WIRE_PONG
2018-04-01T05:28:42.372Z lightningd(1159): lightning_channeld-032c4b954f0f171b694b5e8e8323589e54196b48cf2efc27692513a360cb11d76f chan #881: Peer connection lost
2018-04-01T05:28:42.372Z lightningd(1159): 032c4b954f0f171b694b5e8e8323589e54196b48cf2efc27692513a360cb11d76f chan #881: Peer transient failure in CHANNELD_AWAITING_LOCKIN: lightning_channeld: Owning subdaemon lightning_channeld died (62208)                                                                                                             2018-04-01T05:28:42.378Z lightning_gossipd(1167): Forgetting remote peer 02ad68e300e0ff99fcb7fcfc7bcd62d4fd94061bdce708a1e8c9b429aab04e17bd
2018-04-01T05:28:42.379Z lightningd(1159): lightning_channeld-029441be72bfeef4bee881b44f52a601726e5be7c5d6cf9bb8f4f20123ea524ff7 chan #833: peer_out WIRE_PONG                 2018-04-01T05:28:42.379Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: peer_out WIRE_PONG                 2018-04-01T05:28:42.379Z lightning_gossipd(1167): Received channel_update for channel 515131:577:1(0) now ACTIVE
2018-04-01T05:28:42.379Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: peer_in WIRE_SHUTDOWN
2018-04-01T05:28:42.379Z lightning_gossipd(1167): Received channel_update for channel 515802:736:0(0) now ACTIVE                                                               2018-04-01T05:28:42.379Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: UPDATE WIRE_CHANNEL_GOT_SHUTDOWN   2018-04-01T05:28:42.393Z lightning_gossipd(1167): Received channel_update for channel 515798:1597:0(1) now ACTIVE
2018-04-01T05:28:42.394Z lightning_gossipd(1167): Received channel_update for channel 515282:319:0(1) now ACTIVE
2018-04-01T05:28:42.394Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: Trying commit
2018-04-01T05:28:42.394Z lightning_gossipd(1167): Received channel_update for channel 515409:429:0(0) now ACTIVE
2018-04-01T05:28:42.394Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: Can't send commit: nothing to send
2018-04-01T05:28:42.394Z lightning_gossipd(1167): Received channel_update for channel 515506:1077:0(1) now ACTIVE                                                              2018-04-01T05:28:42.394Z lightning_gossipd(1167): Received channel_update for channel 515519:844:1(0) now ACTIVE
2018-04-01T05:28:42.394Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: peer_out WIRE_SHUTDOWN
2018-04-01T05:28:42.394Z lightning_gossipd(1167): Received channel_update for channel 515454:1348:0(1) now ACTIVE                                                              2018-04-01T05:28:42.394Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: UPDATE WIRE_CHANNEL_SHUTDOWN_COMPLETE
2018-04-01T05:28:42.394Z lightning_gossipd(1167): Received channel_update for channel 515419:1416:0(0) now ACTIVE                                                              2018-04-01T05:28:42.394Z lightningd(1159): lightning_channeld-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: UPDATE WIRE_CHANNEL_SHUTDOWN_COMPLETE                                                                                                                                                                             2018-04-01T05:28:42.410Z lightningd(1159): lightning_closingd-027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: pid 17724, msgfd 19                2018-04-01T05:28:42.426Z lightningd(1159): 027eae72368a57dc9d0c26de4fce5637117e7968f422bdca3d169704fadf8b436b chan #957: State changed from CHANNELD_AWAITING_LOCKIN to CLOSINGD_SIGEXCHANGE                                                                                                                                                                  2018-04-01T05:28:42.426Z lightningd(1159): channel state CHANNELD_AWAITING_LOCKIN should be CHANNELD_SHUTTING_DOWN
2018-04-01T05:28:42.426Z lightningd(1159): FATAL SIGNAL 6 RECEIVED
2018-04-01T05:28:42.470Z lightningd(1159): backtrace: lightningd/log.c:494 (log_crash) 0x415f89                                                                                2018-04-01T05:28:42.470Z lightningd(1159): backtrace: (null):0 ((null)) 0x7fdb982e24af                                                                                         2018-04-01T05:28:42.470Z lightningd(1159): backtrace: (null):0 ((null)) 0x7fdb982e2428
2018-04-01T05:28:42.470Z lightningd(1159): backtrace: (null):0 ((null)) 0x7fdb982e4029
2018-04-01T05:28:42.470Z lightningd(1159): backtrace: lightningd/log.c:592 (fatal) 0x4163da                                                                                    2018-04-01T05:28:42.471Z lightningd(1159): backtrace: lightningd/channel.c:276 (channel_set_state) 0x409115                                                                    2018-04-01T05:28:42.471Z lightningd(1159): backtrace: lightningd/channel_control.c:106 (peer_start_closingd_after_shutdown) 0x409b4c                                           2018-04-01T05:28:42.471Z lightningd(1159): backtrace: lightningd/channel_control.c:137 (channel_msg) 0x409d28
2018-04-01T05:28:42.471Z lightningd(1159): backtrace: lightningd/subd.c:504 (sd_msg_read) 0x42b9c7
2018-04-01T05:28:42.472Z lightningd(1159): backtrace: lightningd/subd.c:330 (read_fds) 0x42b2dc
2018-04-01T05:28:42.472Z lightningd(1159): backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x4644b0                                                                                2018-04-01T05:28:42.472Z lightningd(1159): backtrace: ccan/ccan/io/io.c:387 (do_plan) 0x464f87
2018-04-01T05:28:42.472Z lightningd(1159): backtrace: ccan/ccan/io/io.c:397 (io_ready) 0x464fc5
2018-04-01T05:28:42.472Z lightningd(1159): backtrace: ccan/ccan/io/poll.c:310 (io_loop) 0x46690f
2018-04-01T05:28:42.473Z lightningd(1159): backtrace: lightningd/lightningd.c:407 (main) 0x414739
2018-04-01T05:28:42.473Z lightningd(1159): backtrace: (null):0 ((null)) 0x7fdb982cd82f
2018-04-01T05:28:42.473Z lightningd(1159): backtrace: (null):0 ((null)) 0x403448
2018-04-01T05:28:42.473Z lightningd(1159): backtrace: (null):0 ((null)) 0xffffffffffffffff

cdecker · 2018-04-01T20:51:36Z

I was mainly interested in seeing state transitions prior to getting into the locked up state that keeps failing.

My guess is that we managed to continue the shutdown process, but loaded the channel awaiting lockin from the DB somehow. You can probably recover by manually changing the DB entry's state, however that doesn't solve the underlying problem.

robtex · 2018-04-01T21:14:23Z

sorry about the missing linebreaks in the log btw. saw that now.
it seems there are different channels getting shutdown now, so manual fixing a specific one probably won't help.
for the record my node is still trying to catch up and is at block 458128 right now. could that cause issues like this?

ZmnSCPxj · 2018-04-01T23:42:33Z

I believe spec changed to allow shutdown message before lock-in: lightning/bolts#355

I have not managed to find a transition from CHANNELD_AWAITING_LOCKIN to CHANNELD_SHUTTING_DOWN in our code: it should be possible given the spec allows shutdown to be sent during lockin. Or, alternatively allow this direct transition from CHANNELD_AWAITING_LOCKIN to CLOSINGD_SIGEXCHANGE

for the record my node is still trying to catch up and is at block 458128 right now. could that cause issues like this?

Yes, but, it is this reason, that the spec was changed to allow shutdown to be sent even during lockin.

Fixes: ElementsProject#1308 Signed-off-by: Rusty Russell <[email protected]>

This was referenced Apr 1, 2018

stopping after STATUS_FAIL_INTERNAL_ERROR: hand_back_peer unknown peer #1270

Closed

lightning_channeld: Writing out status 65520: Broken pipe #1269

Closed

Reduce rescanning on startup #1179

Closed

cdecker assigned rustyrussell Apr 1, 2018

ZmnSCPxj mentioned this issue Apr 2, 2018

Allow close and dev-fail to work on channels in state awaiting_lockin #1161

Closed

rustyrussell added a commit to rustyrussell/lightning that referenced this issue Apr 3, 2018

channeld: accept SHUTDOWN before channel is locked.

c50a73e

Fixes: ElementsProject#1308 Signed-off-by: Rusty Russell <[email protected]>

ZmnSCPxj mentioned this issue Apr 3, 2018

Shutdown while awaiting lockin #1313

Merged

cdecker closed this as completed in 1773b03 Apr 3, 2018

Saibato pushed a commit to Saibato/lightning that referenced this issue Apr 17, 2018

channeld: accept SHUTDOWN before channel is locked.

a2a0617

Fixes: ElementsProject#1308 Signed-off-by: Rusty Russell <[email protected]>

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

lightningd keeps crashing with FATAL SIGNAL 6 RECEIVED #1308

lightningd keeps crashing with FATAL SIGNAL 6 RECEIVED #1308

robtex commented Apr 1, 2018 •

edited by cdecker

Loading

cdecker commented Apr 1, 2018

Uh oh!

robtex commented Apr 1, 2018

Uh oh!

robtex commented Apr 1, 2018

Uh oh!

cdecker commented Apr 1, 2018

Uh oh!

robtex commented Apr 1, 2018

Uh oh!

ZmnSCPxj commented Apr 1, 2018

Uh oh!

lightningd keeps crashing with FATAL SIGNAL 6 RECEIVED #1308

lightningd keeps crashing with FATAL SIGNAL 6 RECEIVED #1308

Comments

robtex commented Apr 1, 2018 • edited by cdecker Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Issue and Steps to Reproduce

getinfo output

cdecker commented Apr 1, 2018

Uh oh!

robtex commented Apr 1, 2018

Uh oh!

robtex commented Apr 1, 2018

Uh oh!

cdecker commented Apr 1, 2018

Uh oh!

robtex commented Apr 1, 2018

Uh oh!

ZmnSCPxj commented Apr 1, 2018

Uh oh!

robtex commented Apr 1, 2018 •

edited by cdecker

Loading

`getinfo` output