lightningd crashes with folgore

[urza]

Not sure if this is the same problem as this #87 ?

This is end of my lightningd crashlog:

+152544.422963718 plugin-folgore_pluginIO_IN: 7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22746970203d20303030303030303030303030303030303030303239623830356263633863653862636539346531376432666666343933623438353430643034306239616132652c2068656164657273203d203834333831382f38343338313820283130302e3025292c20636668656164657273203d203834333831382f3834333831382c20696e626f756e64203d20302f31362c206f7574626f756e64203d2031302f38202838292c20636f6e6e656374696e67203d20302f382c20616464726573736573203d203531303331227d2c226a736f6e727063223a22322e30227d7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22696e76656e746f727920626c6f636b207175657565203d20302c20726571756573746564203d20302c206d656d706f6f6c203d2030227d2c226a736f6e727063223a22322e30227d
+152544.422998820 plugin-folgore_pluginINFO: tip = 000000000000000000029b805bcc8ce8bce94e17d2fff493b48540d040b9aa2e, headers = 843818/843818 (100.0%), cfheaders = 843818/843818, inbound = 0/16, outbound = 10/8 (8), connecting = 0/8, addresses = 51031
+152544.423156844 plugin-folgore_pluginINFO: inventory block queue = 0, requested = 0, mempool = 0
+152546.083933935 lightningdIO_OUT: "cln:getrawblockbyheight#10482"
+152546.084047438 plugin-folgore_pluginIO_IN: 7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a226465627567222c226d657373616765223a2263616c6c2067657420626c6f636b20627920686569676874227d2c226a736f6e727063223a22322e30227d7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22636c6e2072657175657374207b5c226865696768745c223a3834333831387d227d2c226a736f6e727063223a22322e30227d
+152546.084057778 plugin-folgore_pluginDEBUG: call get block by height
+152546.084180430 plugin-folgore_pluginINFO: cln request {\"height\":843818}
+152549.950520289 plugin-folgore_pluginINFO: Killing plugin: exited during normal operation
+152549.950561310 lightningdBROKEN: The Bitcoin backend died.
+152549.989468353 lightningdBROKEN: FATAL SIGNAL 6 (version v24.02.2)
+152549.989497345 lightningdBROKEN: backtrace: common/daemon.c:38 (send_backtrace) 0x55b93c84efe6
+152549.989508565 lightningdBROKEN: backtrace: common/daemon.c:75 (crashdump) 0x55b93c84f035
+152549.989515345 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f593981f51f
+152549.989524934 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f59398739fc
+152549.989531775 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f593981f475
+152549.989540226 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f59398057f2
+152549.989546955 lightningdBROKEN: backtrace: lightningd/log.c:1025 (fatal_vfmt) 0x55b93c7fcc37
+152549.989555595 lightningdBROKEN: backtrace: lightningd/log.c:1035 (fatal) 0x55b93c7fccd6
+152549.989562946 lightningdBROKEN: backtrace: lightningd/bitcoind.c:36 (bitcoin_destructor) 0x55b93c7cff7f
+152549.989572876 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:246 (notify) 0x55b93c9cb08f
+152549.989579387 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:437 (del_tree) 0x55b93c9cb162
+152549.989588336 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:521 (tal_free) 0x55b93c9cb6c7
+152549.989594827 lightningdBROKEN: backtrace: lightningd/plugin.c:457 (plugin_kill) 0x55b93c81ffc5
+152549.989603807 lightningdBROKEN: backtrace: lightningd/plugin.c:879 (plugin_conn_finish) 0x55b93c8202f9
+152549.989611127 lightningdBROKEN: backtrace: ccan/ccan/io/poll.c:246 (destroy_conn) 0x55b93c9c0e49
+152549.989619648 lightningdBROKEN: backtrace: ccan/ccan/io/poll.c:252 (destroy_conn_close_fd) 0x55b93c9c0e6f
+152549.989627277 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:246 (notify) 0x55b93c9cb08f
+152549.989633708 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:437 (del_tree) 0x55b93c9cb162
+152549.989641548 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:521 (tal_free) 0x55b93c9cb6c7
+152549.989647728 lightningdBROKEN: backtrace: ccan/ccan/io/io.c:450 (io_close) 0x55b93c9bf9f2
+152549.989652878 lightningdBROKEN: backtrace: ccan/ccan/io/poll.c:457 (io_loop) 0x55b93c9c1487
+152549.989658078 lightningdBROKEN: backtrace: lightningd/io_loop_with_timers.c:22 (io_loop_with_timers) 0x55b93c7f4d88
+152549.989664178 lightningdBROKEN: backtrace: lightningd/lightningd.c:1425 (main) 0x55b93c7fa456
+152549.989669598 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f5939806d8f
+152549.989677378 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f5939806e3f
+152549.989682118 lightningdBROKEN: backtrace: (null):0 ((null)) 0x55b93c7ced64
+152549.989686569 lightningdBROKEN: backtrace: (null):0 ((null)) 0xffffffffffffffff

[vincenzopalazzo]

can you post also your lightning configuration? or command line?

I need to see what kind of configuration are you using

P.S: probably nakamoto?

Thanks,

[urza]

@vincenzopalazzo

This is my config:

mainnet

bitcoin-client=nakamoto

disable-plugin=bcli

rgb=000000
alias=clndev2

# db
wallet=sqlite3:///home/alice/.lightning/bitcoin/lightningd.sqlite3

fee-base=0
fee-per-satoshi=50
min-capacity-sat=8000000
htlc-minimum-msat=100000
ignore-fee-limits=true
large-channels

always-use-proxy=false

# offers / bolt12
experimental-offers

# dual funding
experimental-dual-fund

[vincenzopalazzo]

@urza

Ok, nakamoto is a little bit flaky and sometimes crashes for some reason that I am not sure.

Can you enable the log-level=debug in this way we can track down what it is going on?

I am assuming this is another instance of #62

[urza]

Running with debug logging, will update here when it crashes.

[vincenzopalazzo]

Running with debug logging, will update here when it crashes.

Keep me posted, in this way, we try to reproduce. I will run also mine with Nakamoto for a bit

[urza]

@vincenzopalazzo Can we nudge it to spawn more processes? Maybe the crashing might be related to CPU exhaustion? How to I make it spawn two more processes so it again utilizes all 4 cores that system has? It is sitting on 2 cores 100% this time.. I would like to push it to 4 cores again...

[vincenzopalazzo]

You can't because folgore is a single process (maybe with nakamoto no because it required to be spawn)

If folgore is consuming the 100 CPU usually means that it is not attached to any cor lightning instance, and the only thing that you can do is kill it

[urza]

We have another crash, here is end of the log:

+81132.408958327 lightningdIO_OUT: "cln:getrawblockbyheight#14171"
+81132.422396231 plugin-folgore_pluginIO_IN: 7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a226465627567222c226d657373616765223a2263616c6c2067657420626c6f636b20627920686569676874227d2c226a736f6e727063223a22322e30227d
+81132.422406641 plugin-folgore_pluginDEBUG: call get block by height
+81132.422653567 plugin-folgore_pluginIO_IN: 7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22636c6e2072657175657374207b5c226865696768745c223a3532303539307d227d2c226a736f6e727063223a22322e30227d
+81132.422660517 plugin-folgore_pluginINFO: cln request {\"height\":520590}
+81132.423252063 gossipdDEBUG: channel_announcement: got reply for 514798x115x0...
+81133.424240335 plugin-folgore_pluginIO_IN: 7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22746970203d20303030303030303030303030303030303030303232323164363861643733613666663635333865616563333661663665646261373362363932613430343336302c2068656164657273203d203834343432372f38343434323720283130302e3025292c20636668656164657273203d203834343432372f3834343432372c20696e626f756e64203d20302f31362c206f7574626f756e64203d20382f38202838292c20636f6e6e656374696e67203d20302f382c20616464726573736573203d203538393038227d2c226a736f6e727063223a22322e30227d7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22696e76656e746f727920626c6f636b207175657565203d20302c20726571756573746564203d20312c206d656d706f6f6c203d2030227d2c226a736f6e727063223a22322e30227d
+81133.424276195 plugin-folgore_pluginINFO: tip = 00000000000000000002221d68ad73a6ff6538eaec36af6edba73b692a404360, headers = 844427/844427 (100.0%), cfheaders = 844427/844427, inbound = 0/16, outbound = 8/8 (8), connecting = 0/8, addresses = 58908
+81133.424605593 plugin-folgore_pluginINFO: inventory block queue = 0, requested = 1, mempool = 0
+81134.327977165 plugin-folgore_pluginINFO: Killing plugin: exited during normal operation
+81134.328017306 lightningdBROKEN: The Bitcoin backend died.
+81134.352657959 lightningdBROKEN: FATAL SIGNAL 6 (version v24.02.2)
+81134.352674659 lightningdBROKEN: backtrace: common/daemon.c:38 (send_backtrace) 0x55dc046edfe6
+81134.352680489 lightningdBROKEN: backtrace: common/daemon.c:75 (crashdump) 0x55dc046ee035
+81134.352684030 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f582403151f
+81134.352688250 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f58240859fc
+81134.352691260 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f5824031475
+81134.352694400 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f58240177f2
+81134.352700960 lightningdBROKEN: backtrace: lightningd/log.c:1025 (fatal_vfmt) 0x55dc0469bc37
+81134.352704440 lightningdBROKEN: backtrace: lightningd/log.c:1035 (fatal) 0x55dc0469bcd6
+81134.352708240 lightningdBROKEN: backtrace: lightningd/bitcoind.c:36 (bitcoin_destructor) 0x55dc0466ef7f
+81134.352713280 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:246 (notify) 0x55dc0486a08f
+81134.352717050 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:437 (del_tree) 0x55dc0486a162
+81134.352721210 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:521 (tal_free) 0x55dc0486a6c7
+81134.352724451 lightningdBROKEN: backtrace: lightningd/plugin.c:457 (plugin_kill) 0x55dc046befc5
+81134.352727961 lightningdBROKEN: backtrace: lightningd/plugin.c:879 (plugin_conn_finish) 0x55dc046bf2f9
+81134.352732071 lightningdBROKEN: backtrace: ccan/ccan/io/poll.c:246 (destroy_conn) 0x55dc0485fe49
+81134.352735151 lightningdBROKEN: backtrace: ccan/ccan/io/poll.c:252 (destroy_conn_close_fd) 0x55dc0485fe6f
+81134.352739631 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:246 (notify) 0x55dc0486a08f
+81134.352742611 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:437 (del_tree) 0x55dc0486a162
+81134.352746081 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:521 (tal_free) 0x55dc0486a6c7
+81134.352749671 lightningdBROKEN: backtrace: ccan/ccan/io/io.c:450 (io_close) 0x55dc0485e9f2
+81134.352752921 lightningdBROKEN: backtrace: ccan/ccan/io/poll.c:457 (io_loop) 0x55dc04860487
+81134.352756961 lightningdBROKEN: backtrace: lightningd/io_loop_with_timers.c:22 (io_loop_with_timers) 0x55dc04693d88
+81134.352761171 lightningdBROKEN: backtrace: lightningd/lightningd.c:1425 (main) 0x55dc04699456
+81134.352764531 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f5824018d8f
+81134.352767412 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f5824018e3f
+81134.352770372 lightningdBROKEN: backtrace: (null):0 ((null)) 0x55dc0466dd64
+81134.352773172 lightningdBROKEN: backtrace: (null):0 ((null)) 0xffffffffffffffff

[vincenzopalazzo]

thanks for reporting, any rust logs somewhere?

I think the plugin crashed for some reason. However, I want to take a look at it. Are you on Mainet?

[urza]

Yes mainnet.
How do I get rust logs?

[urza]

another crash, but I think there's not much new in these logs

+102.340039056 lightningdIO_OUT: "cln:getrawblockbyheight#58"
+102.340546247 plugin-folgore_pluginIO_IN: 7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a226465627567222c226d657373616765223a2263616c6c2067657420626c6f636b20627920686569676874227d2c226a736f6e727063223a22322e30227d7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22636c6e2072657175657374207b5c226865696768745c223a3834343432387d227d2c226a736f6e727063223a22322e30227d
+102.340558847 plugin-folgore_pluginDEBUG: call get block by height
+102.340929866 plugin-folgore_pluginINFO: cln request {\"height\":844428}
+102.341092380 plugin-folgore_pluginIO_IN: 7b226964223a22636c6e3a676574726177626c6f636b6279686569676874233538222c226a736f6e727063223a22322e30222c22726573756c74223a7b22626c6f636b223a6e756c6c2c22626c6f636b68617368223a6e756c6c7d7d
+106.290891241 plugin-folgore_pluginIO_IN: 7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22746970203d20303030303030303030303030303030303030303232323164363861643733613666663635333865616563333661663665646261373362363932613430343336302c2068656164657273203d203834343432372f38343434353320283130302e3025292c20636668656164657273203d203834343432372f3834343432372c20696e626f756e64203d20302f31362c206f7574626f756e64203d20372f38202837292c20636f6e6e656374696e67203d20312f382c20616464726573736573203d203539313031227d2c226a736f6e727063223a22322e30227d7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22696e76656e746f727920626c6f636b207175657565203d20302c20726571756573746564203d20302c206d656d706f6f6c203d2030227d2c226a736f6e727063223a22322e30227d
+106.292030608 plugin-folgore_pluginINFO: tip = 00000000000000000002221d68ad73a6ff6538eaec36af6edba73b692a404360, headers = 844427/844453 (100.0%), cfheaders = 844427/844427, inbound = 0/16, outbound = 7/8 (7), connecting = 1/8, addresses = 59101
+106.292197853 plugin-folgore_pluginINFO: inventory block queue = 0, requested = 0, mempool = 0
+108.110449296 plugin-folgore_pluginIO_IN: 7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22446973636f6e6e65637465642066726f6d2039322e3131382e36302e32373a383333332028706565722074696d6564206f75743a205c22636f6e6e656374696f6e5c2229227d2c226a736f6e727063223a22322e30227d7b226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a22696e666f222c226d657373616765223a22436f6e6e656374696e6720746f2070656572203138382e302e3136392e3232393a38333333227d2c226a736f6e727063223a22322e30227d
+108.111473260 plugin-folgore_pluginINFO: Disconnected from 92.118.60.27:8333 (peer timed out: \"connection\")
+108.111885539 plugin-folgore_pluginINFO: Connecting to peer 188.0.169.229:8333
+112.648732409 plugin-folgore_pluginINFO: Killing plugin: exited during normal operation
+112.648902513 lightningdBROKEN: The Bitcoin backend died.
+112.673885766 lightningdBROKEN: FATAL SIGNAL 6 (version v24.02.2)
+112.673932837 lightningdBROKEN: backtrace: common/daemon.c:38 (send_backtrace) 0x556bc6769fe6
+112.673967828 lightningdBROKEN: backtrace: common/daemon.c:75 (crashdump) 0x556bc676a035
+112.674021169 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f68079a051f
+112.674054520 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f68079f49fc
+112.674085781 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f68079a0475
+112.674116751 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f68079867f2
+112.674164723 lightningdBROKEN: backtrace: lightningd/log.c:1025 (fatal_vfmt) 0x556bc6717c37
+112.674198093 lightningdBROKEN: backtrace: lightningd/log.c:1035 (fatal) 0x556bc6717cd6
+112.674231114 lightningdBROKEN: backtrace: lightningd/bitcoind.c:36 (bitcoin_destructor) 0x556bc66eaf7f
+112.674265225 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:246 (notify) 0x556bc68e608f
+112.674315686 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:437 (del_tree) 0x556bc68e6162
+112.674349107 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:521 (tal_free) 0x556bc68e66c7
+112.674381287 lightningdBROKEN: backtrace: lightningd/plugin.c:457 (plugin_kill) 0x556bc673afc5
+112.674413028 lightningdBROKEN: backtrace: lightningd/plugin.c:879 (plugin_conn_finish) 0x556bc673b2f9
+112.674467770 lightningdBROKEN: backtrace: ccan/ccan/io/poll.c:246 (destroy_conn) 0x556bc68dbe49
+112.674500980 lightningdBROKEN: backtrace: ccan/ccan/io/poll.c:252 (destroy_conn_close_fd) 0x556bc68dbe6f
+112.674534352 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:246 (notify) 0x556bc68e608f
+112.674593073 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:437 (del_tree) 0x556bc68e6162
+112.674632394 lightningdBROKEN: backtrace: ccan/ccan/tal/tal.c:521 (tal_free) 0x556bc68e66c7
+112.674664964 lightningdBROKEN: backtrace: ccan/ccan/io/io.c:450 (io_close) 0x556bc68da9f2
+112.674697176 lightningdBROKEN: backtrace: ccan/ccan/io/poll.c:457 (io_loop) 0x556bc68dc487
+112.674743177 lightningdBROKEN: backtrace: lightningd/io_loop_with_timers.c:22 (io_loop_with_timers) 0x556bc670fd88
+112.674805908 lightningdBROKEN: backtrace: lightningd/lightningd.c:1425 (main) 0x556bc6715456
+112.674846339 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f6807987d8f
+112.674878290 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7f6807987e3f
+112.674909820 lightningdBROKEN: backtrace: (null):0 ((null)) 0x556bc66e9d64
+112.674939981 lightningdBROKEN: backtrace: (null):0 ((null)) 0xffffffffffffffff

[vincenzopalazzo]

To see the rust backtrace you should enable the env variable before running lightningd

See https://stackoverflow.com/questions/54055139/how-to-pass-rust-backtrace-1-when-running-a-rust-binary-installed-in-debian

Yes mainnet.

I see, sorry for this experience, idk why you are using nakamoto on mainet, it required some iteration as the readme claims, but you can use other backend like esplora or bitcoin core in prune mode with nakamoto as fallback backend.