bkpr-inspect crashing plugin, perhaps related to multifundchannel use #6800

harvhat · 2023-10-22T09:16:44Z

Issue and Steps to Reproduce

Of my 12 channels 4 for them crash plugin-bookkeeper when attempting to run

lightning-cli bkpr-inspect <peer_id>

Perhaps of note (or not) multifundchannel was used to fund these channels in two transactions, each transaction only has 1 channel that isn't crashing bkpr-inspect. Also all my channels funded singularly using fundchannel aren't causing issues.

2023-10-22T07:42:18.636Z INFO    plugin-clnrest.py: Killing plugin: disabled itself: No module named 'gunicorn'
2023-10-22T07:42:19.262Z INFO    plugin-backup.py: root        : Comparing backup version 133779 versus first write version 133780
2023-10-22T07:42:19.262Z INFO    plugin-backup.py: Comparing backup version 133779 versus first write version 133780
2023-10-22T07:42:19.262Z INFO    plugin-backup.py: root        : Versions match up
2023-10-22T07:42:19.262Z INFO    plugin-backup.py: Versions match up
2023-10-22T07:42:21.853Z INFO    connectd: Static Tor service onion address: "wor65jgzyeqkxawsyag7uknykt5aszf2zsaajyu6oppworz4jk5ygwid.onion:9736,127.0.0.1:9736" bound from extern port 9736 
2023-10-22T07:42:21.910Z INFO    plugin-bcli: bitcoin-cli initialized and connected to bitcoind.
2023-10-22T07:42:35.912Z INFO    lightningd: --------------------------------------------------
2023-10-22T07:42:35.912Z INFO    lightningd: Server started with public key 02cce866b659a12f14e29efccc3c240eaa16bfee3c763bdfddc9808244738c4cb3, alias StreamPipe (color #4aff00) and lightningd v23.08.1
2023-10-22T07:44:40.212Z INFO    02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148-channeld-chan#15: Peer connection lost
2023-10-22T07:44:40.214Z INFO    02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148-chan#15: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (62208)
2023-10-22T07:44:40.215Z INFO    03ae9f91a0cb8ff43840e3c322c4c61f019d8c1c3cea15a25cfc425ac605e61a4a-channeld-chan#14: Peer connection lost
2023-10-22T07:44:40.215Z INFO    03ae9f91a0cb8ff43840e3c322c4c61f019d8c1c3cea15a25cfc425ac605e61a4a-chan#14: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (62208)
2023-10-22T07:44:40.216Z INFO    03ecb3ee55ba6324d40bea174de096dc9134cb35d990235723b37ae9b5c49f4f53-channeld-chan#19: Peer connection lost
2023-10-22T07:44:40.216Z INFO    03ecb3ee55ba6324d40bea174de096dc9134cb35d990235723b37ae9b5c49f4f53-chan#19: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (62208)
2023-10-22T07:44:40.216Z INFO    03ba0dc26e137f7fc5406908aaf614807cde5010a56b39973d68377fb0aa77e5d5-channeld-chan#2: Peer connection lost
2023-10-22T07:44:40.216Z INFO    03ba0dc26e137f7fc5406908aaf614807cde5010a56b39973d68377fb0aa77e5d5-chan#2: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (62208)
2023-10-22T07:44:40.218Z INFO    024bfaf0cabe7f874fd33ebf7c6f4e5385971fc504ef3f492432e9e3ec77e1b5cf-channeld-chan#6: Peer connection lost
2023-10-22T07:44:40.219Z INFO    024bfaf0cabe7f874fd33ebf7c6f4e5385971fc504ef3f492432e9e3ec77e1b5cf-chan#6: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (62208)
2023-10-22T07:44:40.220Z INFO    031240c4973c2687b5295a9bcae10539a4f2e51d35fd5689734bff2c6819629e3d-channeld-chan#1: Peer connection lost
2023-10-22T07:44:40.220Z INFO    031240c4973c2687b5295a9bcae10539a4f2e51d35fd5689734bff2c6819629e3d-chan#1: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (62208)
2023-10-22T08:04:36.962Z INFO    031240c4973c2687b5295a9bcae10539a4f2e51d35fd5689734bff2c6819629e3d-channeld-chan#1: Peer connection lost
2023-10-22T08:04:36.963Z INFO    031240c4973c2687b5295a9bcae10539a4f2e51d35fd5689734bff2c6819629e3d-chan#1: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (62208)
2023-10-22T08:04:46.247Z INFO    plugin-bookkeeper: Killing plugin: exited during normal operation
2023-10-22T08:04:46.248Z **BROKEN** plugin-bookkeeper: Plugin marked as important, shutting down lightningd!

`getinfo` output

{
   "id": "02cce866b659a12f14e29efccc3c240eaa16bfee3c763bdfddc9808244738c4cb3",
   "alias": "StreamPipe",
   "color": "4aff00",
   "num_peers": 12,
   "num_pending_channels": 0,
   "num_active_channels": 12,
   "num_inactive_channels": 0,
   "address": [
      {
         "type": "torv3",
         "address": "wor65jgzyeqkxawsyag7uknykt5aszf2zsaajyu6oppworz4jk5ygwid.onion",
         "port": 9736
      }
   ],
   "binding": [
      {
         "type": "ipv4",
         "address": "127.0.0.1",
         "port": 9736
      }
   ],
   "version": "v23.08.1",
   "blockheight": 813312,
   "network": "bitcoin",
   "fees_collected_msat": 1422599,
   "lightning-dir": "/home/bitcoin/.lightning/bitcoin",
   "our_features": {
      "init": "08a0000a0269a2",
      "node": "88a0000a0269a2",
      "channel": "",
      "invoice": "02000002024100"
   }
}

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

harvhat · 2023-10-29T10:31:30Z

I've open another set of three channels using multifundchannel and again bkpr-inspect works for only one of them, crashing lightningd on the other two. In this case and the previous two cases referred to above the channel that works is the last one listed in the accounts table in the sqlite3 db.

harvhat33 · 2023-12-02T22:41:00Z

If anyone actually cares about this bug it is reproducable on regtest (using the account_id not the peer_id as that was a typo in the OP)

source contrib/startup_regtest.sh
start_ln 4
connect 1 2
connect 1 3
connect 1 4
fund_nodes
l1-cli listpeerchannels
l1-cli close 03c21776dbf44a0f2ef1a58742056d5fe09dbab60a054a18c5ac18dfc1d3300115
bitcoin-cli -datadir="$PATH_TO_BITCOIN" -regtest generatetoaddress 5 "$ADDRESS"
l1-cli listfunds
l1-cli listpeers
l1-cli multifundchannel '[{"id":"03c21776dbf44a0f2ef1a58742056d5fe09dbab60a054a18c5ac18dfc1d3300115","amount":"100000sat"},{"id":"02f081f38929a054740c1bc107dc026e306ecced49c57926c483ef5ee07a2d2de2","amount":"200000sat"},{"id":"03b01a79afd28b80a16350c07fb0880f57e859b718de794ce77684e88c4827213f","amount":"300000sat"}]'
bitcoin-cli -datadir="$PATH_TO_BITCOIN" -regtest generatetoaddress 100 "$ADDRESS"
l1-cli listfunds
l1-cli bkpr-listbalances
{
   "accounts": [
      {
         "account": "wallet",
         "balances": [
            {
               "balance_msat": 99399429000,
               "coin_type": "bcrt"
            }
         ]
      },
      {
         "account": "582224f6b7678c7239142f1dc3428e60c36ad0a2cbac2e81134f6a7b40d55f09",
         "peer_id": "03c21776dbf44a0f2ef1a58742056d5fe09dbab60a054a18c5ac18dfc1d3300115",
         "we_opened": true,
         "account_closed": true,
         "account_resolved": true,
         "resolved_at_block": 124,
         "balances": [
            {
               "balance_msat": 0,
               "coin_type": "bcrt"
            }
         ]
      },
      {
         "account": "cda9bf1ff902298a9d81beb4445ae74527cac776a204acc32cc603479e00eeac",
         "peer_id": "03c21776dbf44a0f2ef1a58742056d5fe09dbab60a054a18c5ac18dfc1d3300115",
         "we_opened": true,
         "account_closed": false,
         "account_resolved": false,
         "balances": [
            {
               "balance_msat": 100000000,
               "coin_type": "bcrt"
            }
         ]
      },
      {
         "account": "7f6a8c3fc87ae04eca9b4220a85493ae6937da6fd0469f237960a3a9a911d235",
         "peer_id": "02f081f38929a054740c1bc107dc026e306ecced49c57926c483ef5ee07a2d2de2",
         "we_opened": true,
         "account_closed": false,
         "account_resolved": false,
         "balances": [
            {
               "balance_msat": 200000000,
               "coin_type": "bcrt"
            }
         ]
      },
      {
         "account": "2a8e270c03c7d8d806eb7263b5198aa4c6f7b125365869252c5639062ee43f50",
         "peer_id": "03b01a79afd28b80a16350c07fb0880f57e859b718de794ce77684e88c4827213f",
         "we_opened": true,
         "account_closed": false,
         "account_resolved": false,
         "balances": [
            {
               "balance_msat": 300000000,
               "coin_type": "bcrt"
            }
         ]
      }
   ]
}
l1-cli bkpr-inspect 582224f6b7678c7239142f1dc3428e60c36ad0a2cbac2e81134f6a7b40d55f09
{ ...snip... normal listing showed up here ...}
l1-cli bkpr-inspect cda9bf1ff902298a9d81beb4445ae74527cac776a204acc32cc603479e00eeac
bookkeeper: plugins/bkpr/recorder.c:365: find_account_onchain_fees: Assertion `ok' failed.
bookkeeper: FATAL SIGNAL 6 (version v23.11-1-g84f2206)
0x564449abccbb send_backtrace
	common/daemon.c:33
0x564449abcd43 crashdump
	common/daemon.c:75
0x7f7389c0efcf ???
	./signal/../sysdeps/unix/sysv/linux/x86_64/libc_sigaction.c:0
0x7f7389c5dd3c __pthread_kill_implementation
	./nptl/pthread_kill.c:44
0x7f7389c0ef31 __GI_raise
	../sysdeps/posix/raise.c:26
0x7f7389bf9471 __GI_abort
	./stdlib/abort.c:79
0x7f7389bf9394 __assert_fail_base
	./assert/assert.c:92
0x7f7389c07e31 __GI___assert_fail
	./assert/assert.c:101
0x564449aa7e0d find_account_onchain_fees
	plugins/bkpr/recorder.c:365
0x564449aa2d40 json_inspect
	plugins/bkpr/bookkeeper.c:259
0x564449aadc4d ld_command_handle
	plugins/libplugin.c:1645
0x564449aade49 ld_read_json_one
	plugins/libplugin.c:1721
0x564449aaded9 ld_read_json
	plugins/libplugin.c:1741
0x564449bf073c next_plan
	ccan/ccan/io/io.c:59
0x564449bf0bc3 do_plan
	ccan/ccan/io/io.c:407
0x564449bf0c5c io_ready
	ccan/ccan/io/io.c:417
0x564449bf24b9 io_loop
	ccan/ccan/io/poll.c:453
0x564449aae537 plugin_main
	plugins/libplugin.c:1948
0x564449aa3874 main
	plugins/bkpr/bookkeeper.c:1849
0x7f7389bfa1c9 __libc_start_call_main
	../sysdeps/nptl/libc_start_call_main.h:58
0x7f7389bfa284 __libc_start_main_impl
	../csu/libc-start.c:360
0x564449a9da10 ???
	???:0
0xffffffffffffffff ???
	???:0
bookkeeper: FATAL SIGNAL 11 (version v23.11-1-g84f2206)
0x564449abccbb send_backtrace
	common/daemon.c:33
0x564449abcd43 crashdump
	common/daemon.c:75
0x7f7389c0efcf ???
	./signal/../sysdeps/unix/sysv/linux/x86_64/libc_sigaction.c:0
0x0 ???
	???:0
{
   "code": -4,
   "message": "Plugin terminated before replying to RPC call."
}

vincenzopalazzo · 2023-12-03T00:38:29Z

cc @niftynei 😄

niftynei · 2023-12-09T17:43:11Z

@evansmj and I were able to reproduce and debug, patch incoming; tldr there's a SQL command that's grouping on the wrong thing and causing a crash.

Good news is all your data is/should be correct, just need a software update to be able to see it without crashing.

evansmj · 2023-12-14T18:29:26Z

ready for review ^

evansmj · 2024-04-30T18:45:56Z

@harvhat @harvhat33 A fix has been merged to v24.02, just wondering if this has resolved your issue?

vincenzopalazzo added the in diagnostic issue under diagnostic label Dec 3, 2023

vincenzopalazzo added this to the v24.02 milestone Dec 3, 2023

niftynei self-assigned this Dec 6, 2023

evansmj mentioned this issue Dec 13, 2023

Fix onchain fees lookup query #6939

Merged

cdecker removed this from the v24.02 milestone Feb 13, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

bkpr-inspect crashing plugin, perhaps related to multifundchannel use #6800

bkpr-inspect crashing plugin, perhaps related to multifundchannel use #6800

harvhat commented Oct 22, 2023

harvhat commented Oct 29, 2023 •

edited

harvhat33 commented Dec 2, 2023 •

edited

vincenzopalazzo commented Dec 3, 2023

niftynei commented Dec 9, 2023

evansmj commented Dec 14, 2023

evansmj commented Apr 30, 2024 •

edited

bkpr-inspect crashing plugin, perhaps related to multifundchannel use #6800

bkpr-inspect crashing plugin, perhaps related to multifundchannel use #6800

Comments

harvhat commented Oct 22, 2023

Issue and Steps to Reproduce

getinfo output

harvhat commented Oct 29, 2023 • edited

harvhat33 commented Dec 2, 2023 • edited

vincenzopalazzo commented Dec 3, 2023

niftynei commented Dec 9, 2023

evansmj commented Dec 14, 2023

evansmj commented Apr 30, 2024 • edited

`getinfo` output

harvhat commented Oct 29, 2023 •

edited

harvhat33 commented Dec 2, 2023 •

edited

evansmj commented Apr 30, 2024 •

edited