plugin-sql crashes after payed hold invoices expired
Closed this issue · 2 comments
HaosGames commented
I payed two hold invoices. Both expired. Then the sql plugin crashed:
Jul 30 19:11:46 benno lightningd[1120641]: INFO 0123456789-chan#161: htlc 3619 failed from 1th node with code 0x1007 (WIRE_TEMPORARY_CHANNEL_FAILURE)
Jul 30 19:11:46 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 4: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
Jul 30 19:11:46 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 4: Payment deadline expired, not retrying (partial-)payment 0123456789/4
Jul 30 19:15:54 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 0: Initial limit on max HTLCs: 1275, Destination 0123456789 has 85 channels, assuming 15 HTLCs per channel
Jul 30 19:15:54 benno lightningd[1120641]: INFO lightningd: Sending 12886024msat in onion to deliver 12884000msat
Jul 30 19:15:55 benno lightningd[1120641]: INFO 0123456789-chan#160: htlc 1048 failed from 0th node with code 0x400a (WIRE_UNKNOWN_NEXT_PEER)
Jul 30 19:15:55 benno lightningd[1120641]: UNUSUAL plugin-pay: cmd 34 partid 0: Intermediate node 0123456789 reported strange error code 400a (PERM|10)
Jul 30 19:15:55 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 0: failed: WIRE_UNKNOWN_NEXT_PEER (reply from remote)
Jul 30 19:15:56 benno lightningd[1120641]: INFO lightningd: Sending 12887287msat in onion to deliver 12884000msat
Jul 30 19:15:59 benno lightningd[1120641]: INFO 0123456789-chan#30: htlc 789 failed from 0th node with code 0x1007 (WIRE_TEMPORARY_CHANNEL_FAILURE)
Jul 30 19:15:59 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 1: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
Jul 30 19:15:59 benno lightningd[1120641]: INFO lightningd: Sending 12886178msat in onion to deliver 12884000msat
Jul 30 19:16:07 benno lightningd[1120641]: INFO 0123456789-chan#23: htlc 1021 failed from 1th node with code 0x1007 (WIRE_TEMPORARY_CHANNEL_FAILURE)
Jul 30 19:16:07 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 2: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
Jul 30 19:16:08 benno lightningd[1120641]: INFO lightningd: Sending 12886062msat in onion to deliver 12884000msat
Jul 30 19:16:14 benno lightningd[1120641]: INFO 0123456789-chan#21: htlc 2963 failed from 2th node with code 0x1007 (WIRE_TEMPORARY_CHANNEL_FAILURE)
Jul 30 19:16:14 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 3: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
Jul 30 19:16:14 benno lightningd[1120641]: INFO lightningd: Sending 12885024msat in onion to deliver 12884000msat
Jul 30 19:16:17 benno lightningd[1120641]: INFO 0123456789-chan#161: htlc 3620 failed from 1th node with code 0x1007 (WIRE_TEMPORARY_CHANNEL_FAILURE)
Jul 30 19:16:17 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 4: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
Jul 30 19:16:17 benno lightningd[1120641]: INFO lightningd: Sending 12885024msat in onion to deliver 12884000msat
Jul 30 19:16:23 benno lightningd[1120641]: INFO 0123456789-chan#161: htlc 3621 failed from 2th node with code 0x1007 (WIRE_TEMPORARY_CHANNEL_FAILURE)
Jul 30 19:16:23 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 5: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
Jul 30 19:16:23 benno lightningd[1120641]: INFO lightningd: Sending 12886556msat in onion to deliver 12884000msat
Jul 30 19:16:27 benno lightningd[1120641]: INFO 0123456789-chan#21: htlc 2964 failed from 2th node with code 0x1007 (WIRE_TEMPORARY_CHANNEL_FAILURE)
Jul 30 19:16:27 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 6: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
Jul 30 19:16:27 benno lightningd[1120641]: INFO lightningd: Sending 12886107msat in onion to deliver 12884000msat
Jul 30 19:16:34 benno lightningd[1120641]: INFO 0123456789-chan#21: htlc 2965 failed from 2th node with code 0x1007 (WIRE_TEMPORARY_CHANNEL_FAILURE)
Jul 30 19:16:34 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 7: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
Jul 30 19:16:34 benno lightningd[1120641]: INFO lightningd: Sending 12885152msat in onion to deliver 12884000msat
Jul 30 19:16:38 benno lightningd[1120641]: INFO 0123456789-chan#161: htlc 3622 failed from 1th node with code 0x1007 (WIRE_TEMPORARY_CHANNEL_FAILURE)
Jul 30 19:16:38 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 8: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
Jul 30 19:16:38 benno lightningd[1120641]: INFO lightningd: Sending 12886182msat in onion to deliver 12884000msat
Jul 30 19:16:55 benno lightningd[1120641]: INFO 0123456789-chan#21: htlc 2966 failed from 3th node with code 0x1007 (WIRE_TEMPORARY_CHANNEL_FAILURE)
Jul 30 19:16:55 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 9: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
Jul 30 19:16:55 benno lightningd[1120641]: INFO plugin-pay: cmd 34 partid 9: Payment deadline expired, not retrying (partial-)payment 0123456789/9
Jul 30 19:25:46 benno lightningd[1120761]: sql: FATAL SIGNAL 11 (version v24.02.2)
Jul 30 19:25:46 benno lightningd[1120761]: 0x4199b6 send_backtrace
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x419a4c crashdump
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x7f03ddb2df2f ???
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x41ed6f json_get_membern
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x41ee0d json_get_member
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x40508a process_json_obj
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x4050b5 process_json_obj
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x405543 process_json_list
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x405605 process_json_result
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x405775 default_list_done
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x40b01c handle_rpc_reply
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x40b1bf rpc_read_response_one
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x40b26c rpc_conn_read_response
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x4b4ccf next_plan
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x4b5153 do_plan
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x4b51ec io_ready
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x4b6a54 io_loop
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x40b5f1 plugin_main
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x406c3b main
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x7f03ddb1810d __libc_start_call_main
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x7f03ddb181c8 __libc_start_main_alias_1
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0x4038e4 _start
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:46 benno lightningd[1120761]: 0xffffffffffffffff ???
Jul 30 19:25:46 benno lightningd[1120761]: ???:0
Jul 30 19:25:47 benno lightningd[1120641]: INFO plugin-chanbackup: Updating the SCB
Jul 30 19:25:48 benno lightningd[1120641]: INFO plugin-sql: Killing plugin: exited during normal operation
Jul 30 19:25:48 benno lightningd[1120641]: **BROKEN** plugin-sql: Plugin marked as important, shutting down lightningd!
Jul 30 19:25:48 benno lightningd[1120641]: INFO 0123456789-chan#167: Peer transient failure in CHANNELD_AWAITING_LOCKIN: channeld: Owning subdaemon channeld died (9)
Jul 30 19:25:48 benno lightningd[1120641]: INFO 0123456789-chan#23: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (9)
Jul 30 19:25:48 benno lightningd[1120641]: INFO 0123456789-chan#24: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (9)
Jul 30 19:25:48 benno lightningd[1120641]: INFO 0123456789-chan#157: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (9)
Jul 30 19:25:48 benno lightningd[1120641]: INFO 0123456789-chan#30: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (9)
Jul 30 19:25:48 benno lightningd[1120641]: INFO 0123456789-chan#160: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (9)
Jul 30 19:25:48 benno lightningd[1120641]: INFO 0123456789-chan#161: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (9)
Jul 30 19:25:48 benno lightningd[1120641]: INFO 0123456789-chan#41: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (9)
Jul 30 19:25:48 benno lightningd[1120641]: INFO 0123456789-chan#21: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (9)
Jul 30 19:27:17 benno systemd[1]: clightning.service: Main process exited, code=exited, status=1/FAILURE
Jul 30 19:27:17 benno systemd[1]: clightning.service: Failed with result 'exit-code'.
Jul 30 19:27:17 benno systemd[1]: clightning.service: Consumed 1d 2h 10min 1.883s CPU time, received 58.4G IP traffic, sent 29.3G IP traffic.
Jul 30 19:27:27 benno systemd[1]: clightning.service: Scheduled restart job, restart counter is at 1.
Jul 30 19:27:27 benno systemd[1]: Starting clightning.service...
Jul 30 19:27:27 benno lightningd[2028991]: INFO lightningd: v24.02.2
Jul 30 19:27:32 benno lightningd[2028991]: INFO plugin-bcli: bitcoin-cli initialized and connected to bitcoind.
Jul 30 19:28:06 benno lightningd[2028991]: INFO plugin-monitor.py: Plugin monitor.py initialized
Jul 30 19:28:06 benno systemd[1]: Started clightning.service.
rustyrussell commented
Hmm, but who is calling sql? It doesn't do anything unless someone calls it. What plugins do you have installed?
rustyrussell commented
OK, invoices were a red herring. But I fixed the issue, because the backtrace showed an object inside an object in our SQL, which only happens in one place.
Thanks!