Skip to content

segfault on splicing and segfault on subsequent reconnects #6658

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
achow101 opened this issue Sep 8, 2023 · 8 comments · Fixed by #6677
Closed

segfault on splicing and segfault on subsequent reconnects #6658

achow101 opened this issue Sep 8, 2023 · 8 comments · Fixed by #6677
Assignees
@ddustin
Milestone
v23.11

Comments

@achow101
Copy link
Contributor

achow101 commented Sep 8, 2023

@Sjors tried to splice in to a channel I have with him and the resulting failure also crashed my node. Attempting to reconnect results in subsequent crashing as well.

Logs:

Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.410Z DEBUG   <sjors node id>-channeld-chan#1777: peer_in WIRE_STFU
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.410Z DEBUG   <sjors node id>-channeld-chan#1777: STFU initiator was remote.
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.410Z DEBUG   <sjors node id>-channeld-chan#1777: Sending peer that we want to STFU.
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.410Z DEBUG   <sjors node id>-channeld-chan#1777: peer_out WIRE_STFU
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.410Z UNUSUAL <sjors node id>-channeld-chan#1777: STFU complete: we are quiescent
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.410Z UNUSUAL <sjors node id>-channeld-chan#1777: STFU complete: setting stfu_wait_single_msg = true
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.498Z DEBUG   <sjors node id>-channeld-chan#1777: peer_in WIRE_SPLICE
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.498Z DEBUG   <sjors node id>-channeld-chan#1777: peer_out WIRE_SPLICE_ACK
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.586Z DEBUG   <sjors node id>-channeld-chan#1777: peer_in WIRE_TX_ADD_INPUT
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.586Z DEBUG   <sjors node id>-channeld-chan#1777: peer_out WIRE_TX_COMPLETE
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.674Z DEBUG   <sjors node id>-channeld-chan#1777: peer_in WIRE_TX_ADD_INPUT
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.674Z DEBUG   <sjors node id>-channeld-chan#1777: peer_out WIRE_TX_COMPLETE
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.761Z DEBUG   <sjors node id>-channeld-chan#1777: peer_in WIRE_TX_ADD_OUTPUT
Sep 08 16:54:48 mempool lightningd[3190693]: 2023-09-08T20:54:48.761Z DEBUG   <sjors node id>-channeld-chan#1777: peer_out WIRE_TX_COMPLETE
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.639Z DEBUG   <sjors node id>-gossipd: Received channel_update for channel 739253x679x0/1 now ACTIVE
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.640Z DEBUG   <sjors node id>-gossipd: Received channel_update for channel 765136x756x1/0 now ACTIVE
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.640Z DEBUG   <sjors node id>-gossipd: Received channel_update for channel 766924x395x1/0 now DISABLED
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.640Z DEBUG   <sjors node id>-gossipd: Received channel_update for channel 729917x963x0/1 now DISABLED
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.640Z DEBUG   <sjors node id>-gossipd: Received channel_update for channel 774787x1000x0/1 now DISABLED
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.640Z DEBUG   <sjors node id>-gossipd: Received node_announcement for node 0226f6d2f68eba4ac3abd6e8f93646abc3686e691cd0a1d71ec65213662c07ecf4
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.640Z DEBUG   <sjors node id>-gossipd: Received node_announcement for node 022b74592de1ef344ede43249274c4b0b1d9b676d3be7bf0d55dec431a1b937cec
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.641Z DEBUG   <sjors node id>-gossipd: Received channel_update for channel 740660x3096x1/0 now ACTIVE
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.641Z DEBUG   <sjors node id>-gossipd: Received node_announcement for node 029740c95d98bdc3f21f464d99d85789081e54828e184d49039fdb863a51ad51ed
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.641Z DEBUG   <sjors node id>-gossipd: Received node_announcement for node 038344ee4b8e20e581a4f5993dd2d8e261aeabe44c07402a300333805e5567f709
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.641Z DEBUG   <sjors node id>-gossipd: Received node_announcement for node 030d2583cd27ed322e880da3aae0867f0b5314fe437a8ca4876fd84de828ebc835
Sep 08 16:55:04 mempool lightningd[3190693]: 2023-09-08T20:55:04.747Z DEBUG   <sjors node id>-gossipd: Received node_announcement for node 02d47f64f8fd535febb521923c401fb5bd82b6b74a3382457cd6316af353c7d6aa
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.288Z DEBUG   <sjors node id>-channeld-chan#1777: peer_in WIRE_TX_COMPLETE
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.288Z DEBUG   connectd: drain_peer draining subd!
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.288Z DEBUG   <sjors node id>-lightningd: peer_disconnect_done
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.288Z DEBUG   <sjors node id>-lightningd: Will try reconnect in 1 seconds
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.288Z DEBUG   connectd: maybe_free_peer freeing peer!
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.288Z DEBUG   plugin-funder: Cleaning up inflights for peer id <sjors node id>
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.288Z DEBUG   hsmd: Client: Received message 3 from client
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.297Z DEBUG   <sjors node id>-channeld-chan#1777: Splice accepter adding inflight: cHNidP8BAgQCAAAAAQMEf08MAAEEAQIBBQEBAQYBAwH7BAIAAAAAAQDsAgAAAAABAWxIuRqu4U0rDzN6aezpL>
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.297Z DEBUG   <sjors node id>-channeld-chan#1777: Sending master 7216
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.297Z DEBUG   <sjors node id>-chan#1777: lightningd adding inflight with txid 89b67e7b7069dab68da3e8058beea4be024b9d39ace772302d32f6f302cef94d
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.313Z DEBUG   <sjors node id>-channeld-chan#1777: ... , awaiting 7217
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.313Z DEBUG   <sjors node id>-channeld-chan#1777: Got it!
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.313Z DEBUG   <sjors node id>-channeld-chan#1777: Splice accepter: we commit first
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.313Z DEBUG   <sjors node id>-channeld-chan#1777: send_commit_part(splice: 0, remote_splice: 0)
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.313Z DEBUG   <sjors node id>-hsmd: Got WIRE_HSMD_SIGN_REMOTE_COMMITMENT_TX
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.313Z DEBUG   <sjors node id>-channeld-chan#1777: Creating commit_sig signature 1 304402204f494172a9da321ae45a37b07160d892a5df8ba77f948e6c0165e39014e880cd022033f5ac838a>
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.313Z DEBUG   hsmd: Client: Received message 19 from client
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.314Z DEBUG   <sjors node id>-channeld-chan#1777: Telling master we're about to commit...
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.314Z DEBUG   <sjors node id>-channeld-chan#1777: Sending master 1020
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.327Z DEBUG   <sjors node id>-channeld-chan#1777: ... , awaiting 1120
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.327Z DEBUG   <sjors node id>-channeld-chan#1777: Got it!
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.327Z DEBUG   <sjors node id>-channeld-chan#1777: Sending commit_sig with 0 htlc sigs
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.327Z DEBUG   <sjors node id>-channeld-chan#1777: send_commit_part(splice: 0, remote_splice: 24000)
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.328Z DEBUG   <sjors node id>-hsmd: Got WIRE_HSMD_SIGN_REMOTE_COMMITMENT_TX
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.328Z DEBUG   hsmd: Client: Received message 19 from client
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.328Z DEBUG   <sjors node id>-channeld-chan#1777: Creating commit_sig signature 1 30440220194e57bf18d8057b0a70c2320143c160ac2dd1ad1de5304ac06210af85890f95022059de98ae1f>
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.328Z DEBUG   <sjors node id>-channeld-chan#1777: peer_out WIRE_COMMITMENT_SIGNED
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.328Z DEBUG   <sjors node id>-channeld-chan#1777: peer_out WIRE_COMMITMENT_SIGNED
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.328Z DEBUG   <sjors node id>-channeld-chan#1777: peer_in WIRE_WARNING
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.328Z DEBUG   <sjors node id>-channeld-chan#1777: peer_out WIRE_WARNING
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.328Z DEBUG   <sjors node id>-channeld-chan#1777: billboard perm: Got incorrect message from peer: WIRE_WARNING (should be WIRE_REVOKE_AND_ACK) [warning channel 8aa0ec0>
Sep 08 16:55:20 mempool lightningd[3190693]: 2023-09-08T20:55:20.328Z INFO    <sjors node id>-chan#1777: Peer transient failure in CHANNELD_NORMAL: channeld WARNING: Got incorrect message from peer: WIRE_WARNING (should be WIRE_REVO>
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.445Z DEBUG   gossipd: REPLY WIRE_GOSSIPD_GET_ADDRS_REPLY with 0 fds
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.503Z DEBUG   hsmd: Client: Received message 1 from client
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.539Z DEBUG   <sjors node id>-connectd: Connected out, starting crypto
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.592Z DEBUG   <sjors node id>-connectd: Connect IN
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.592Z DEBUG   <sjors node id>-connectd: peer_out WIRE_INIT
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.630Z DEBUG   hsmd: Client: Received message 1 from client
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.630Z DEBUG   <sjors node id>-connectd: Connect OUT
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.630Z DEBUG   <sjors node id>-connectd: peer_out WIRE_INIT
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.680Z DEBUG   <sjors node id>-connectd: peer_in WIRE_INIT
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.680Z DEBUG   lightningd: Calling peer_connected hook of plugin chanbackup
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.680Z DEBUG   <sjors node id>-connectd: Handed peer, entering loop
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.680Z DEBUG   <sjors node id>-gossipd: seeker: starting gossip
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.680Z DEBUG   lightningd: Plugin chanbackup returned from peer_connected hook call
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.680Z DEBUG   <sjors node id>-chan#1777: Peer has reconnected, state CHANNELD_NORMAL: connecting subd
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.693Z DEBUG   <sjors node id>-channeld-chan#1777: pid 3674777, msgfd 78
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.693Z DEBUG   <sjors node id>-chan#1777: Already have funding locked in
Sep 08 16:55:21 mempool lightningd[3190693]: lightningd: FATAL SIGNAL 11 (version v23.08)
Sep 08 16:55:21 mempool lightningd[3190693]: 0x47815e send_backtrace
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x4781f4 crashdump
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x7f056e395d2f ???
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x4920a6 uses_witness
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x492def linearize_wtx
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x492ec5 linearize_tx
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x4937c0 towire_bitcoin_tx
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x4b5e9a towire_inflight
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x4b0528 towire_channeld_init
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x4112fc peer_start_channeld
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x43db19 connect_activate_subd
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x43f8c5 peer_connected_hook_final
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x44f249 plugin_hook_callback
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x44a36b plugin_response_handle
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x44d541 plugin_read_json_one
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x44d68e plugin_read_json
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x551d91 next_plan
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x552215 do_plan
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x5522ae io_ready
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x55349f io_loop
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x425661 io_loop_with_timers
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x429c70 main
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x7f056e380acd __libc_start_call_main
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x7f056e380b88 __libc_start_main_alias_2
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0x405cd4 _start
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 0xffffffffffffffff ???
Sep 08 16:55:21 mempool lightningd[3190693]:         ???:0
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: FATAL SIGNAL 11 (version v23.08)
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (send_backtrace) 0x4781a9
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (crashdump) 0x4781f4
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x7f056e395d2f
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (uses_witness) 0x4920a6
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (linearize_wtx) 0x492def
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (linearize_tx) 0x492ec5
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (towire_bitcoin_tx) 0x4937c0
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (towire_inflight) 0x4b5e9a
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (towire_channeld_init) 0x4b0528
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (peer_start_channeld) 0x4112fc
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (connect_activate_subd) 0x43db19
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (peer_connected_hook_final) 0x43f8c5
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (plugin_hook_callback) 0x44f249
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (plugin_response_handle) 0x44a36b
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (plugin_read_json_one) 0x44d541
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (plugin_read_json) 0x44d68e
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (next_plan) 0x551d91
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (do_plan) 0x552215
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (io_ready) 0x5522ae
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (io_loop) 0x55349f
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (io_loop_with_timers) 0x425661
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (main) 0x429c70
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (__libc_start_call_main) 0x7f056e380acd
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (__libc_start_main_alias_2) 0x7f056e380b88
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 (_start) 0x405cd4
Sep 08 16:55:21 mempool lightningd[3190693]: 2023-09-08T20:55:21.707Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0xffffffffffffffff
Sep 08 16:55:21 mempool lightningd[3190693]: Log dumped in crash.log.20230908205521
Sep 08 16:55:23 mempool lightningd[3190714]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190711]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190715]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190701]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190713]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190708]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190716]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190710]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190700]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190707]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190709]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190705]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190706]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool lightningd[3190704]: Lost connection to the RPC socket.
Sep 08 16:55:23 mempool systemd[1]: clightning.service: Main process exited, code=dumped, status=11/SEGV
Sep 08 16:55:23 mempool systemd[1]: clightning.service: Failed with result 'core-dump'.
Sep 08 16:55:23 mempool systemd[1]: clightning.service: Consumed 58.607s CPU time, received 83.2M IP traffic, sent 1.9M IP traffic.
Sep 08 16:55:24 mempool systemd[1]: clightning.service: Scheduled restart job, restart counter is at 1.
Sep 08 16:55:24 mempool systemd[1]: Stopped Core Lightning daemon.
@Sjors
Copy link
Contributor

Sjors commented Sep 8, 2023

After @achow101 deleted one database entry, every time I attempt to connect it immedidately disconnects:

"status": [
    "CHANNELD_NORMAL:Received warning channel ...: commit_sig with no changes (again!)",
    "CHANNELD_NORMAL:Will attempt reconnect in 300 seconds"
  ],

@Sjors
Copy link
Contributor

Sjors commented Sep 9, 2023

What sqlite query do I run to get this thing out of my database?

@Sjors
Copy link
Contributor

Sjors commented Sep 9, 2023

On my end there's nothing in the channel_funding_inflights table.

So every time we reconnect I get:

2023-09-09T15:42:14.110Z INFO    xxxx-chan#13917: Peer transient failure in CHANNELD_NORMAL: channeld WARNING: warning channel yyyy: commit_sig with no changes (again!)

@rustyrussell rustyrussell added this to the v23.11 milestone Sep 12, 2023
@ddustin ddustin mentioned this issue Sep 13, 2023
Merged
@ddustin
Copy link
Collaborator

ddustin commented Sep 13, 2023

Note that PR #6677 addresses the crashing issue however the removing the of the inflight (and related testing) must still be addressed, as is discussed over in this issue #6656 (comment)

@Sjors
Copy link
Contributor

Sjors commented Sep 19, 2023

I updated to v23.08.1 but the commit_sig with no changes (again!) issue persists. But the other issue is still open, so I guess that's not fixed yet.

@ddustin
Copy link
Collaborator

ddustin commented Sep 22, 2023

Should be fixed on master but it didn't make it into v23.08.1

@Sjors
Copy link
Contributor

Sjors commented Nov 7, 2023 •
edited
Loading

@ddustin I still can't reconnect with v23.11rc1 (on my end, @achow101 might be on an older version):

2023-11-07T02:31:42.306Z DEBUG   03xxx-connectd: Connected out, starting crypto
2023-11-07T02:31:42.414Z DEBUG   03xxx-connectd: Connect OUT
2023-11-07T02:31:42.415Z DEBUG   03xxx-connectd: peer_out WIRE_INIT
2023-11-07T02:31:42.515Z DEBUG   03xxx-connectd: peer_in WIRE_INIT
2023-11-07T02:31:42.515Z DEBUG   03xxx-lightningd: Peer says it sees our address as: x.x.x.x:55464
2023-11-07T02:31:42.515Z DEBUG   03xxx-connectd: Handed peer, entering loop
2023-11-07T02:31:42.515Z DEBUG   03xxx-gossipd: seeker: disabling gossip
2023-11-07T02:31:42.516Z DEBUG   03xxx-chan#13917: Peer has reconnected, state CHANNELD_NORMAL: connecting subd
2023-11-07T02:31:42.532Z DEBUG   03xxx-channeld-chan#13917: pid 526760, msgfd 84
2023-11-07T02:31:42.532Z DEBUG   03xxx-chan#13917: Already have funding locked in (and ready to announce)
2023-11-07T02:31:42.533Z DEBUG   03xxx-connectd: peer_out WIRE_GOSSIP_TIMESTAMP_FILTER
2023-11-07T02:31:42.533Z DEBUG   03xxx-channeld-chan#13917: option_static_remotekey = 1, option_anchor_outputs = 0 option_anchors_zero_fee_htlc_tx = 0
2023-11-07T02:31:42.533Z DEBUG   03xxx-channeld-chan#13917: init REMOTE: remote_per_commit = 03xxx, old_remote_per_commit = 02xx next_idx_local = 3 next_idx_remote = 2 revocations_received = 0 feerates { SENT_ADD_REVOCATION:7763 SENT_ADD_ACK_COMMIT:7760 RCVD_ADD_ACK_REVOCATION:7760 } range 1207-171810 blockheights { RCVD_ADD_ACK_REVOCATION:0 }, our current 815651
2023-11-07T02:31:42.533Z DEBUG   03xxx-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2023-11-07T02:31:42.533Z DEBUG   03xxx-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2023-11-07T02:31:42.534Z DEBUG   03xxx-channeld-chan#13917: peer_out WIRE_CHANNEL_REESTABLISH
2023-11-07T02:31:42.534Z DEBUG   03xxx-channeld-chan#13917: billboard: Sent reestablish, waiting for theirs
2023-11-07T02:31:42.791Z DEBUG   03xxx-connectd: peer_in WIRE_GOSSIP_TIMESTAMP_FILTER
2023-11-07T02:31:42.791Z DEBUG   03xxx-channeld-chan#13917: peer_in WIRE_CHANNEL_REESTABLISH
2023-11-07T02:31:42.791Z DEBUG   03xxx-channeld-chan#13917: Got reestablish commit=1 revoke=1 inflights: 0, active splices: 0
2023-11-07T02:31:42.791Z DEBUG   03xxx-channeld-chan#13917: next_revocation_number = 1
2023-11-07T02:31:42.792Z DEBUG   03xxx-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2023-11-07T02:31:42.792Z DEBUG   03xxx-channeld-chan#13917: option_static_remotekey: fields are correct
2023-11-07T02:31:42.792Z DEBUG   03xxx-channeld-chan#13917: Retransmitting commitment, feerate LOCAL=7763 REMOTE=7760, blockheight LOCAL=0 REMOTE=0
2023-11-07T02:31:42.792Z DEBUG   03xxx-channeld-chan#13917: send_commit_part(splice: 0, remote_splice: 0)
2023-11-07T02:31:42.794Z DEBUG   03xxx-hsmd: Got WIRE_HSMD_SIGN_REMOTE_COMMITMENT_TX
2023-11-07T02:31:42.794Z DEBUG   03xxx-channeld-chan#13917: Creating commit_sig signature 1 30xxx for tx 02xxx wscript 52xxx key 03xx
2023-11-07T02:31:42.795Z DEBUG   03xxx-channeld-chan#13917: peer_out WIRE_COMMITMENT_SIGNED
2023-11-07T02:31:42.795Z DEBUG   03xxx-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2023-11-07T02:31:42.795Z DEBUG   03xxx-channeld-chan#13917: peer_out WIRE_REVOKE_AND_ACK
2023-11-07T02:31:42.796Z DEBUG   03xxx-channeld-chan#13917: No upgrade: we retransmitted
2023-11-07T02:31:42.796Z DEBUG   03xxx-channeld-chan#13917: billboard perm: Reconnected, and reestablished.
2023-11-07T02:31:42.796Z DEBUG   03xxx-channeld-chan#13917: Exchanging announcement signatures.
2023-11-07T02:31:42.797Z DEBUG   03xxx-hsmd: Got WIRE_HSMD_CANNOUNCEMENT_SIG_REQ
2023-11-07T02:31:42.797Z DEBUG   03xxx-channeld-chan#13917: peer_out WIRE_ANNOUNCEMENT_SIGNATURES
2023-11-07T02:31:42.797Z DEBUG   03xxx-channeld-chan#13917: billboard: Channel ready for use. Channel announced.
2023-11-07T02:31:42.929Z DEBUG   03xxx-channeld-chan#13917: billboard: Channel ready for use. Channel announced.
2023-11-07T02:31:42.929Z DEBUG   03xxx-lightningd: peer_disconnect_done
2023-11-07T02:31:42.929Z DEBUG   03xxx-lightningd: Will try reconnect in 300 seconds
2023-11-07T02:31:42.929Z DEBUG   03xxx-channeld-chan#13917: billboard: Channel ready for use. Channel announced.
2023-11-07T02:31:42.930Z DEBUG   plugin-funder: Cleaning up inflights for peer id 03xxx
2023-11-07T02:31:42.930Z DEBUG   03xxx-channeld-chan#13917: Can't send commit: waiting for revoke_and_ack
2023-11-07T02:31:42.930Z DEBUG   03xxx-channeld-chan#13917: peer_in WIRE_ANNOUNCEMENT_SIGNATURES
2023-11-07T02:31:42.930Z DEBUG   03xxx-channeld-chan#13917: billboard: Channel ready for use. Channel announced.
2023-11-07T02:31:43.014Z DEBUG   03xxx-channeld-chan#13917: peer_in WIRE_WARNING
2023-11-07T02:31:43.014Z INFO    03xxx-channeld-chan#13917: Received WARNING channel 8axxxx: commit_sig with no changes (again!)
2023-11-07T02:31:43.014Z INFO    03xxx-channeld-chan#13917: Peer connection lost
2023-11-07T02:31:43.014Z INFO    03xxx-chan#13917: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (62208)

@ddustin
Copy link
Collaborator

ddustin commented Nov 7, 2023 •
edited
Loading

@ddustin I still can't reconnect with v23.11rc1 (on my end, @achow101 might be on an older version):

I suspect this will be fixed by #6840 eventually

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@ddustin ddustin

Labels
None yet
Projects
None yet
Milestone
v23.11
Development

Successfully merging a pull request may close this issue.

Splice-out Regression and Restart Fixes ddustin/lightning
5 participants
@Sjors @ddustin @rustyrussell @achow101 and others