Crash on 25.02

[daywalker90]

So i wrote a plugin to hook into rpc_command for pay and since only one plugin can do that i disable xpay-handle-pay and wrote it myself. I encountered a crash on my mainnet node that i tried to replicate with some tests on regtest but was unable to.

Mar 28 10:37:18  lightningd[3568263]: cln-askrene: FATAL SIGNAL 11 (version v25.02)
Mar 28 10:37:18  lightningd[3568263]: 0x564650aa6fa6 send_backtrace
Mar 28 10:37:18  lightningd[3568263]:         common/daemon.c:33
Mar 28 10:37:18  lightningd[3568263]: 0x564650aa7033 crashdump
Mar 28 10:37:18  lightningd[3568263]:         common/daemon.c:78
Mar 28 10:37:18  lightningd[3568263]: 0x7fe85f9c104f ???
Mar 28 10:37:18  lightningd[3568263]:         ./signal/../sysdeps/unix/sysv/linux/x86_64/libc_sigaction.c:0
Mar 28 10:37:18  lightningd[3568263]: 0x0 ???
Mar 28 10:37:18  lightningd[3568263]:         ???:0
Mar 28 10:37:18  lightningd[3568246]: INFO    plugin-cln-askrene: Killing plugin: exited during normal operation
Mar 28 10:37:18  lightningd[3568246]: **BROKEN** plugin-cln-askrene: Plugin marked as important, shutting down lightningd!

When my plugin was done with the pay->xpay conversion it returned:

{"replace":{"id":"cli:pay#3568741","jsonrpc":"2.0","method":"xpay","params":{"invstring":"lnbc182[...]","layers":["6f0da531ec03f6cd1d3dcf0e0df001ebb7133ddbb7a3a219162a49e3ccc4b89f"],"maxfee":0,"retry_for":180}}}

These are the only logs between the replace response issued and the crash:

Mar 28 10:37:18  lightningd[3568246]: DEBUG   hsmd: Client: Received message 51 from client
Mar 28 10:37:18  lightningd[3568246]: DEBUG   hsmd: preapprove_invoice: check_only=0
Mar 28 10:37:18  lightningd[3568246]: DEBUG   plugin-cln-xpay: notify msg debug: getroutes from 0380ef0209ff1b46c38a37cd40f613d1dae3eba481a909459d6c1434a0e56e5d8c to 0385262f7e9e2eeeba1e7d6182a0efec98e79d01154b76189f3e0b88bcee>
Mar 28 10:37:18  lightningd[3568246]: DEBUG   plugin-cln-xpay: 0: getroutes from 0380ef0209ff1b46c38a37cd40f613d1dae3eba481a909459d6c1434a0e56e5d8c to 0385262f7e9e2eeeba1e7d6182a0efec98e79d01154b76189f3e0b88bcee279dd0
Mar 28 10:37:18  lightningd[3568246]: DEBUG   plugin-sling: Peerchannels refreshed in 3ms
Mar 28 10:37:18  lightningd[3568246]: DEBUG   0380ef0209ff1b46c38a37cd40f613d1dae3eba481a909459d6c1434a0e56e5d8c-hsmd: Got WIRE_HSMD_ECDH_REQ
Mar 28 10:37:18  lightningd[3568246]: DEBUG   hsmd: Client: Received message 1 from client
Mar 28 10:37:18  lightningd[3568246]: DEBUG   0282ccffe2f7fd63b0d68528dab9cd6cff8f64733d2d730c3eb8fa81e011da930e-connectd: Connect IN
Mar 28 10:37:18  lightningd[3568246]: DEBUG   0282ccffe2f7fd63b0d68528dab9cd6cff8f64733d2d730c3eb8fa81e011da930e-connectd: peer_out WIRE_INIT

When testing this on regtest with the exact same arguments used and a similar network setup and exclude it works. But on mainnet i crashed my node everytime i tried it.

[rustyrussell]

Weird! You can definitely have multiple things on that hook, BTW. But it looks like askrene got upset with whatever you changed the command to?

[daywalker90]

Weird! You can definitely have multiple things on that hook, BTW.

Yes, but:

If two or more plugins try to replace/result/error the same method, only the first plugin in the chain will be respected. Others will be ignored and a warning will be logged.

Can't have that in my plugin.

But it looks like askrene got upset with whatever you changed the command to?

See OP for the replace json, it shouldn't get that upset about it.

I disabled my plugin and recreated what i pass to xpay in a bash script:

#!/bin/bash
bolt11=$1

output=$(lightning-cli listpeerchannels)
invoice=$(lightning-cli decode $bolt11)
payment_hash=$(echo "$invoice" | jq -r '.payment_hash')

lightning-cli askrene-remove-layer $payment_hash
lightning-cli askrene-create-layer $payment_hash false

# Extract the peer_id values using jq and filter out the desired value "X"
peer_ids=$(echo "$output" | jq -r '.channels[].peer_id | select(. != "02187352cc4b1856b9604e0a79e1bc9b301be7e0c14acbbb8c29f7051d507127d7" and . != "0385262f7e9e2eeeba1e7d6182a0efec98e79d01154b76189f3e0b88bcee279dd0" and . != "029c5b14214ca7c1f5334db539dbab266088ba43a40563551efb9458756a94cd94" and . != "030a425f5c69a29db30f6740d4e7df8f5612ef9955078ef4497490015464733dc8" and . != "02c5b5972b05fba2cd2c2d9269a47bc478f73fae0f248a85cb1e5af60a07c1919d")')
peer_ids_array=$(echo "$peer_ids" | awk '{printf "\"%s\",", $0}' | sed 's/,$//')

for peer_id in $peer_ids; do
        lightning-cli askrene-disable-node $payment_hash $peer_id
done


lightning-cli xpay -k maxfee=0 retry_for=180 invstring=$bolt11 layers="[\"$payment_hash\"]"

This also crashes my node with the same crash stacktrace.

I used this invoice (it's probably expired already):

lnbc181620n1pn75vr0pp54dvyyflz4084xzyr9r8xkfefllwv5yphaex3ugmuant8cajenzeqdt8235x2snfvaxxz6m9yqkjq5rp09kk2mn5ypex2en9wfjkucm98gsx2cnyxajr2c3h956xgvf3956xvdnz94sk2wfs95urywp4x5crxcmyxe3nst3q235xjueqwpshjmt9de6zq46ff3xzq3jjg4z453fqf98zqk2024fzq46pf3xy24pvyp3ksetrdvsx7m3q2fhkym6nv968xgrfvcs8g6r9ypkx7cmtypmkzueqwd6kxcm9wdekvatv9csyjapqwa5kcmpqvfjjqatwd3hkx6m9vsszsenpd9kzjgr4dekx2umnypuk7afqvd5x2ct5yphhygrrv9hxxetvyp6ku6tvv96x2unpd3k8jtscqz0yxqzwzsp5l6wcqdjm0xsfu97pwth62w9ys0l7gml7jda4hvwy3n2y29zacq4s9qxpqysgqdsthdwxy3trkwn2d69qsclluaju7ay7suzh4fejwxcgaadeenwk5z20x55uc0ye7qqdhakmd8ed3zgvmhrgmuwn5jp43ra9uakq56dgqtmdkja

[rustyrussell]

Ah, is this actually fixed by #8187 ?

[daywalker90]

Yes crash was happening 100% of the time on 25.02. So i crashed it again immediately upgraded to master and ran command again and it worked, no crash. Thank you!