lightning icon indicating copy to clipboard operation
lightning copied to clipboard
verified publisher icon ElementsProject

Cannot forward htlc over spliced channel?

Open JssDWt opened this issue 2 years ago • 13 comments

Issue and Steps to Reproduce

I'm experimenting with splicing in an LSP scenario.

  • a htlc is intercepted with the htlc acceptor hook
  • a splice-in is initiated, with
    • splice_init
    • splice_update (repeatedly)
    • sign_psbt
    • splice_signed
  • the splice transaction confirms 6 blocks deep
  • the channel is updated to CHANNEL_READY
  • the htlc_accepted hook returns 'continue', with a payload containing the new confirmed short channel id (or the local alias, result is the same)
  • the node fails the htlc with UNKNOWN_NEXT_PEER

Note that this exact scenario does work with regular channel opens. Unfortunately the reason for the failure is not logged.

Some logs from a regtest integration test:

2024-01-18T13:17:13.078Z DEBUG   03c9e234bdd82fb1985e7ae94c3e3037546b2b4d15ebf8614ac7bb1394070b3daf-channeld-chan#1: revoke_and_ack REMOTE: remote_per_commit = 02d64b50170331d9b3f9fd54240fbdd21a1b6ad7a03f0002adeae64d512675bc2a, old_remote_per_commit = 02a6ba1d991bf26b364dbb9f3887aa7848ef8b87524ef40e851e739c6a3ba685c5
2024-01-18T13:17:13.078Z INFO    plugin-cmd_cln_plugin: 14:17:13 cln_plugin.go:117: {\"jsonrpc\":\"2.0\",\"id\":\"cln:htlc_accepted#151\",\"method\":\"htlc_accepted\",\"params\":{\"onion\":{\"payload\":\"13020406422c4004018a06080000010000000000\",\"type\":\"tlv\",\"short_channel_id\":\"1x0x0\",\"forward_msat\":105000000,\"outgoing_cltv_value\":138,\"next_onion\":\"0002aa9fffff30731586698a19ad12159fae6bbd0723876bc6e8b57474574bfdfb95933ed79322af0828bf7b967254ff8c996f33fc25369de5a2053d5baf707deb0555b4709d8f854a1530bf65ff5564b8202fae8fcc70d3a496ef7aa5f3f1dcb8c7295b4912e7d92a6fd83f9ab11426930bef14f45843517da8b1211ee4c0277301efff6c5a950fd3dfab66c15b1d2979fe3cc1ee11f411cf5b74dc85a5f9d5c093fbb413ba3d00d12ba195fe346ed00cf79eb4331ceed0946d0a007a5f36d6776c9528db57384cb0db50efea990146f3ead3321fd93a81e0a431249b00baa5ac3aa0a1b229a4f866f87c4edf3de070cbf5b90bf4d9ace9831eea20ae8920e08eb4585bb0180b35fb1512d5df49e2e1b1a1a0018d4adb8d3d63643c9dd79d44db32e5cbbc2f09673b547a8dc8bca506322c6dc513bd1f8279e38d3f5c0a10a4639b6be0005af1fb5caf692e23fd680dccb469d15f47e642a7eb3ec249e3d508190cb0a0b52b21664f60478f261e17074907e18f097f13d317e01377a832f00797217265799c2872db8beaea54dcee17fda36434fcf99c47780e35838cdb622633c4ece77af7e7e710a5374e4183d43e3d03f84ad009fab3f01027d52a0e0fb6ab7f4dffb7df5b35007d28ae7fb2a8d635e31baed2ddd2f04cbf8a157640db1f01a9e1d3455d48f5bd7648e716888922b67f1a4504e9f0fde1cbe140e012eef0edf0126d8cc26d62a3ef40478486ddbbc3d64d28e2b5ea0d569f34bff50003621fd148a275346084c30d3cd888855080d97586d60961084c302bfa2f290109e6f7bb1888f566c10312678069705285a2d93c5e188300ab9b8f194b68650828e1d9bc2782b3bfcccb7272bf63bd399b4bcac06f42b78a26472e509fe532af17e8a25e6ef035e03efe1a07a2f11ee1bdacdeaa24da9f60698f2fc98260f3fd3b3fdc88f5d3d92ba15fd0bd37190b4d47609dfb1eb17e7c09fc39186556d13c89b23c2107c01bfb224cfa95c2543a33e3920d92c141f7d1360383bb802bb624c68a1219013d1fcb025fc3c84d85934eb88c781b0161d9dc5a70e92991b1dc5e7c441da03b9671f8bb00fe4eab51953712cfec85c4ed396cced9b630c0ce8516bfe00940d1dbf8d3935cb1a43ab3e2803ff4b340deca054649c7de91d84fe944e4e754cc6948a655af673fc9e1187c162e96470d8ba2cec4704a1574e5824ff20a98554746407a5e5009143177fe9ca9fa00bbb55381bc581f1e1c8da850f3a86709c0913a1fc1bcfba24661f533551daa84f637c2f450acc27ecfc53fb1bb5081d4c4ade6533a9bb5658fff3f99046200ee7b180c311d20ab721b9b3e714a12a6a29d685830b4e68880eb75e3311a9e287d2aaee86f59759edc3d98cdeaf3e6f14fd64fff0a4bdc5f84c66a4b74fb1ab59cb5946522e19901b0a358a853e0e12360cad752ac9a45c3a6462ca43f46367cd7ff3c9747df15b6a72ada630b6b4a410e97fb9703dbfdce215e8f13781a45594327ef3997aa691a549f9fd7ff65188db51859fb536c90aa1378d92138bfb25f382c51a0b80d1491be9aadca0cdda0a45674d6b9440370456e0e6cbfc21c788df61eddaa2cffa46e4c1649fb0bdbb839ac4506478598be998a038badac36d87a698187438f66e895b2173417e3a94b72254a73033642ca9f5b6c8af3be50ac3f1000ec930cd1c3536459cbf45ebbcb8cb00711a43b97bde5f05fa728c826d42acd66e5c77b8083009ba4b4e4a170b3be1e506a1d2e17d60dbb317790de01ffccf70da28b6cc91afe6630e2aca53fff9c17d12e4bab231423b5be54166886e1dce829ae9b66a4719553c6a1a84c653c82057006c3c063b0d0cdd82651abcc5aa59e0c64a131b64349e91474bc9350099a4787a2e4bca2a42ff8c3c8a4b2944284d52a7aff87aab8\",\"shared_secret\":\"51e71ec64a5a59b7e9aa25e1de01a762df0474ba65b2f736de75e44409dd06fb\"},\"htlc\":{\"short_channel_id\":\"104x1x0\",\"id\":1,\"amount_msat\":105001105,\"cltv_expiry\":282,\"cltv_expiry_relative\":155,\"payment_hash\":\"9ed29a3b147e800788fa48a93f453f59df6d89fa378556340b3e98302da20e54\"}}}
2024-01-18T13:17:13.080Z DEBUG   03c9e234bdd82fb1985e7ae94c3e3037546b2b4d15ebf8614ac7bb1394070b3daf-channeld-chan#1: Trying commit
2024-01-18T13:17:13.080Z DEBUG   03c9e234bdd82fb1985e7ae94c3e3037546b2b4d15ebf8614ac7bb1394070b3daf-channeld-chan#1: Can't send commit: nothing to send, feechange not wanted ({ RCVD_ADD_ACK_REVOCATION:258 }) blockheight not wanted ({ RCVD_ADD_ACK_REVOCATION:0 })
2024-01-18T13:17:13.088Z DEBUG   plugin-bcli: Feerate min_acceptable raised from 500 perkb to floor of 1000
2024-01-18T13:17:13.090Z DEBUG   hsmd: Client: Received message 28 from client
2024-01-18T13:17:13.091Z DEBUG   lightningd: splice_init input PSBT version 0
2024-01-18T13:17:13.091Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Getting handle_splice_init psbt version 2
2024-01-18T13:17:13.091Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Sending peer that we want to STFU.
2024-01-18T13:17:13.091Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_out WIRE_STFU
2024-01-18T13:17:13.091Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_in WIRE_STFU
2024-01-18T13:17:13.091Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: STFU initiator local.
2024-01-18T13:17:13.091Z UNUSUAL 03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: STFU complete: we are quiescent
2024-01-18T13:17:13.092Z UNUSUAL 03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: STFU complete: setting stfu_wait_single_msg = true
2024-01-18T13:17:13.092Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_out WIRE_SPLICE
2024-01-18T13:17:13.092Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_in WIRE_SPLICE_ACK
2024-01-18T13:17:13.092Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Sending master 7208
2024-01-18T13:17:13.092Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: ... , awaiting 7209
2024-01-18T13:17:13.092Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Got it!
2024-01-18T13:17:13.093Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_out WIRE_TX_ADD_INPUT
2024-01-18T13:17:13.093Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_in WIRE_TX_COMPLETE
2024-01-18T13:17:13.093Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_out WIRE_TX_ADD_INPUT
2024-01-18T13:17:13.093Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_in WIRE_TX_COMPLETE
2024-01-18T13:17:13.093Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_out WIRE_TX_ADD_OUTPUT
2024-01-18T13:17:13.094Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_in WIRE_TX_COMPLETE
2024-01-18T13:17:13.094Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_out WIRE_TX_ADD_OUTPUT
2024-01-18T13:17:13.094Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_in WIRE_TX_COMPLETE
2024-01-18T13:17:13.095Z DEBUG   lightningd: splice_update input PSBT version 2
2024-01-18T13:17:13.095Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_out WIRE_TX_COMPLETE
2024-01-18T13:17:13.095Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Splice adding inflight: cHNidP8BAgQCAAAAAQMEfwAAAAEEAQIBBQECAQYBAwH7BAIAAAAAAQD2AgAAAAABAdzLBTsSwCaQ8ugyKeDV5slhTAtOH7h5sSdlztAqwwbOAQAAAAD9////AtSOAQAAAAAAIgAgJMlw1ZAlqPOagZktJjY5jrcy4RuV5LMwkRWeJs/b/SN3BJcAAAAAACJRIH8Q62QGfo6I9yOHOe4GlwKOleJgL0S9Du7gREubFam0AkcwRAIgWnWQl35AiMp+szH6Oa947QeB6ZM16P8y0IJISrJkVd0CIG0ApwTvwwvP6jgI5eIZIfzzq0UL0iW2sSQrRHmDGl39ASECI4k4d5bbcX9b/28Z1aBg7OLV+ixVvI7YLQJhz6a8R1tzAAAAAQEr1I4BAAAAAAAiACAkyXDVkCWo85qBmS0mNjmOtzLhG5XkszCRFZ4mz9v9IwEOIGR6SNVXhw+A/pfXEMvA+fROBUVxQRvOxONpa8GTiX/zAQ8EAAAAAAEQBAAAAAAM/AlsaWdodG5pbmcBCAgQqUd+LDyuAAEA9gIAAAAAAQHcywU7EsAmkPLoMing1ebJYUwLTh+4ebEnZc7QKsMGzgEAAAAA/f///wLUjgEAAAAAACIAICTJcNWQJajzmoGZLSY2OY63MuEbleSzMJEVnibP2/0jdwSXAAAAAAAiUSB/EOtkBn6OiPcjhznuBpcCjpXiYC9EvQ7u4ERLmxWptAJHMEQCIFp1kJd+QIjKfrMx+jmveO0HgemTNej/MtCCSEqyZFXdAiBtAKcE78MLz+o4COXiGSH886tFC9IltrEkK0R5gxpd/QEhAiOJOHeW23F/W/9vGdWgYOzi1fosVbyO2C0CYc+mvEdbcwAAAAEBK3cElwAAAAAAIlEgfxDrZAZ+joj3I4c57gaXAo6V4mAvRL0O7uBES5sVqbQBDiBkekjVV4cPgP6X1xDLwPn0TgVFcUEbzsTjaWvBk4l/8wEPBAEAAAABEAT9////DPwJbGlnaHRuaW5nAQhOIeFPJgEyugABAwicrwQAAAAAAAEEIgAgJMlw1ZAlqPOagZktJjY5jrcy4RuV5LMwkRWeJs/b/SMM/AlsaWdodG5pbmcBCMNKrRgWyiM2AAEDCIbhkwAAAAAAAQQiUSD17dzXTK9DhPkIHwXxHf/Y64+f8EYzs2B5k3sw+g8PLgz8CWxpZ2h0bmluZwEI0GVA6d0h+MwA
2024-01-18T13:17:13.096Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Sending master 7216
2024-01-18T13:17:13.096Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: lightningd adding inflight with txid ce16ce33e7a722d84775df94e52ee02998de6497763c007da50237bc5b71c044
2024-01-18T13:17:13.098Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: ... , awaiting 7217
2024-01-18T13:17:13.098Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Got it!
2024-01-18T13:17:13.098Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-hsmd: Got WIRE_HSMD_SETUP_CHANNEL
2024-01-18T13:17:13.098Z DEBUG   hsmd: Client: Received message 31 from client
2024-01-18T13:17:13.100Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_in WIRE_COMMITMENT_SIGNED
2024-01-18T13:17:13.100Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2024-01-18T13:17:13.100Z DEBUG   hsmd: Client: Received message 18 from client
2024-01-18T13:17:13.100Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: handle_peer_commit_sig(splice: 205000, remote_splice: 0)
2024-01-18T13:17:13.100Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Received commit
2024-01-18T13:17:13.100Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Derived key 026cce63a74e9ad1025024bf53145c5241b84fc8af236e8999309be59895b1956a from basepoint 026ce119acad4bf4fcf6d5f458a608ef6b25a87951d90a4daa4d6a54b5986958b3, point 02bf08860f45ec6b83aff6fb3bcda0d2fe542510778a265bd9f83e9dd3039b9530
2024-01-18T13:17:13.100Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Received commit_sig with 0 htlc sigs
2024-01-18T13:17:13.101Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-hsmd: Got WIRE_HSMD_VALIDATE_COMMITMENT_TX
2024-01-18T13:17:13.101Z DEBUG   hsmd: Client: Received message 35 from client
2024-01-18T13:17:13.101Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Splice initiator: we commit second
2024-01-18T13:17:13.101Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: send_commit_part(splice: 205000, remote_splice: 0)
2024-01-18T13:17:13.101Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-hsmd: Got WIRE_HSMD_SIGN_REMOTE_COMMITMENT_TX
2024-01-18T13:17:13.101Z DEBUG   hsmd: Client: Received message 19 from client
2024-01-18T13:17:13.101Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Creating commit_sig signature 2 3044022021ff5c6dd4a7fff016a4198f8efcb3ef2777f6e33a935539af7f7657898e805b02204069c07cdc45291fea5df1eaabb79098a8732b8ad413ad6da2600db7447976fa01 for tx 020000000144c0715bbc3702a57d003c769764de9829e02ee594df7547d822a7e733ce16ce0000000000f37c7580024a01000000000000220020d6718177f268d2011ebce0a8dea0de258da178c936016c87ca206f90b5a94a2e22a7040000000000220020c0093cd3f78bf7e107f25b6198f942f4deff2f792021bf496c09e19f574ee7ffef926520 wscript 52210234e17071b7f0b6c58afb8499ad39591501a8f8950ca7f62cf5215c8e84fd48f021039771b3941de16a874d76a2bbc160cd88a6a0573795be8a44cfd3186483d3c4fc52ae key 0234e17071b7f0b6c58afb8499ad39591501a8f8950ca7f62cf5215c8e84fd48f0
2024-01-18T13:17:13.101Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_out WIRE_COMMITMENT_SIGNED
2024-01-18T13:17:13.106Z DEBUG   hsmd: Client: Received message 7 from client
2024-01-18T13:17:13.107Z DEBUG   lightningd: splice_signed input PSBT version 2
2024-01-18T13:17:13.109Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-hsmd: Got WIRE_HSMD_SIGN_SPLICE_TX
2024-01-18T13:17:13.109Z INFO    03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Splice negotation, will not send commit, not recv commit, send signature, recv signature
2024-01-18T13:17:13.109Z DEBUG   hsmd: Client: Received message 29 from client
2024-01-18T13:17:13.109Z INFO    03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Splice signing tx: 0200000002647a48d557870f80fe97d710cbc0f9f44e054571411bcec4e3696bc193897ff3000000000000000000647a48d557870f80fe97d710cbc0f9f44e054571411bcec4e3696bc193897ff30100000000fdffffff029caf04000000000022002024c970d59025a8f39a81992d2636398eb732e11b95e4b33091159e26cfdbfd2386e1930000000000225120f5eddcd74caf4384f9081f05f11dffd8eb8f9ff04633b36079937b30fa0f0f2e7f000000
2024-01-18T13:17:13.109Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_in WIRE_TX_SIGNATURES
2024-01-18T13:17:13.109Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Left STFU mode.
2024-01-18T13:17:13.111Z INFO    03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: State changed from CHANNELD_NORMAL to CHANNELD_AWAITING_SPLICE
2024-01-18T13:17:13.112Z INFO    03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: Watching splice inflight ce16ce33e7a722d84775df94e52ee02998de6497763c007da50237bc5b71c044
2024-01-18T13:17:13.113Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_out WIRE_TX_SIGNATURES
2024-01-18T13:17:13.113Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Splice: we signed second
2024-01-18T13:17:13.113Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: Broadcasting splice tx 02000000000102647a48d557870f80fe97d710cbc0f9f44e054571411bcec4e3696bc193897ff3000000000000000000647a48d557870f80fe97d710cbc0f9f44e054571411bcec4e3696bc193897ff30100000000fdffffff029caf04000000000022002024c970d59025a8f39a81992d2636398eb732e11b95e4b33091159e26cfdbfd2386e1930000000000225120f5eddcd74caf4384f9081f05f11dffd8eb8f9ff04633b36079937b30fa0f0f2e04004730440220745ce3bf225fedc76cf4f287c77f91372e9063896b68dc2cf794e0a651ac260502204c30ab24a09a4a8cc777eb4e41c182f4c050a885eaa07bf853e63263f67f808e014730440220713b8f9533e747b486d0fb015a332316e077b690818b71e0055fead17deec8f802206ce7411a67721121da599d42e85e8f407e0f90da0169207f1306e82e19f7a555014752210234e17071b7f0b6c58afb8499ad39591501a8f8950ca7f62cf5215c8e84fd48f021039771b3941de16a874d76a2bbc160cd88a6a0573795be8a44cfd3186483d3c4fc52ae01409f2e87c0d0436d8c7d30757bb205619475d4bf1a47cf50a87452a992f79d60c5f7c6ac5b3e4ed5939951f33e821a5fb0b4de4b61922e375c4b898d29455eabf97f000000 for channel 647a48d557870f80fe97d710cbc0f9f44e054571411bcec4e3696bc193897ff3.
2024-01-18T13:17:13.113Z DEBUG   lightningd: sendrawtransaction: 02000000000102647a48d557870f80fe97d710cbc0f9f44e054571411bcec4e3696bc193897ff3000000000000000000647a48d557870f80fe97d710cbc0f9f44e054571411bcec4e3696bc193897ff30100000000fdffffff029caf04000000000022002024c970d59025a8f39a81992d2636398eb732e11b95e4b33091159e26cfdbfd2386e1930000000000225120f5eddcd74caf4384f9081f05f11dffd8eb8f9ff04633b36079937b30fa0f0f2e04004730440220745ce3bf225fedc76cf4f287c77f91372e9063896b68dc2cf794e0a651ac260502204c30ab24a09a4a8cc777eb4e41c182f4c050a885eaa07bf853e63263f67f808e014730440220713b8f9533e747b486d0fb015a332316e077b690818b71e0055fead17deec8f802206ce7411a67721121da599d42e85e8f407e0f90da0169207f1306e82e19f7a555014752210234e17071b7f0b6c58afb8499ad39591501a8f8950ca7f62cf5215c8e84fd48f021039771b3941de16a874d76a2bbc160cd88a6a0573795be8a44cfd3186483d3c4fc52ae01409f2e87c0d0436d8c7d30757bb205619475d4bf1a47cf50a87452a992f79d60c5f7c6ac5b3e4ed5939951f33e821a5fb0b4de4b61922e375c4b898d29455eabf97f000000
2024-01-18T13:17:13.114Z DEBUG   02cb80233be1f5e7533ced4a00ea4de530a6e57b28764dcbc79949067b8b4aa6b2-hsmd: Got WIRE_HSMD_CUPDATE_SIG_REQ
2024-01-18T13:17:13.114Z DEBUG   hsmd: Client: Received message 3 from client
2024-01-18T13:17:13.120Z DEBUG   plugin-bcli: sendrawtx exit 0 (/Users/jessedewit/Projects/breez/bitcoin-23.0/bin/bitcoin-cli -regtest -datadir=/Users/jessedewit/Projects/breez/testdir/3141987895/miner4083215304 -rpcport=61257 -rpcuser=... -stdinrpcpass sendrawtransaction 02000000000102647a48d557870f80fe97d710cbc0f9f44e054571411bcec4e3696bc193897ff3000000000000000000647a48d557870f80fe97d710cbc0f9f44e054571411bcec4e3696bc193897ff30100000000fdffffff029caf04000000000022002024c970d59025a8f39a81992d2636398eb732e11b95e4b33091159e26cfdbfd2386e1930000000000225120f5eddcd74caf4384f9081f05f11dffd8eb8f9ff04633b36079937b30fa0f0f2e04004730440220745ce3bf225fedc76cf4f287c77f91372e9063896b68dc2cf794e0a651ac260502204c30ab24a09a4a8cc777eb4e41c182f4c050a885eaa07bf853e63263f67f808e014730440220713b8f9533e747b486d0fb015a332316e077b690818b71e0055fead17deec8f802206ce7411a67721121da599d42e85e8f407e0f90da0169207f1306e82e19f7a555014752210234e17071b7f0b6c58afb8499ad39591501a8f8950ca7f62cf5215c8e84fd48f021039771b3941de16a874d76a2bbc160cd88a6a0573795be8a44cfd3186483d3c4fc52ae01409f2e87c0d0436d8c7d30757bb205619475d4bf1a47cf50a87452a992f79d60c5f7c6ac5b3e4ed5939951f33e821a5fb0b4de4b61922e375c4b898d29455eabf97f000000) 
2024-01-18T13:17:13.121Z DEBUG   wallet: Owning output 1 9691526sat (SEGWIT) txid ce16ce33e7a722d84775df94e52ee02998de6497763c007da50237bc5b71c044
2024-01-18T13:17:14.206Z DEBUG   plugin-bcli: Feerate min_acceptable raised from 500 perkb to floor of 1000
2024-01-18T13:17:15.245Z DEBUG   plugin-bcli: Feerate min_acceptable raised from 500 perkb to floor of 1000
2024-01-18T13:17:16.278Z DEBUG   plugin-bcli: Feerate min_acceptable raised from 500 perkb to floor of 1000
2024-01-18T13:17:16.545Z DEBUG   02cb80233be1f5e7533ced4a00ea4de530a6e57b28764dcbc79949067b8b4aa6b2-hsmd: Got WIRE_HSMD_CUPDATE_SIG_REQ
2024-01-18T13:17:16.545Z DEBUG   hsmd: Client: Received message 3 from client
2024-01-18T13:17:17.319Z DEBUG   plugin-bcli: Feerate min_acceptable raised from 500 perkb to floor of 1000
2024-01-18T13:17:17.598Z DEBUG   02cb80233be1f5e7533ced4a00ea4de530a6e57b28764dcbc79949067b8b4aa6b2-hsmd: Got WIRE_HSMD_CUPDATE_SIG_REQ
2024-01-18T13:17:17.598Z DEBUG   hsmd: Client: Received message 3 from client
2024-01-18T13:17:18.357Z DEBUG   plugin-bcli: Feerate min_acceptable raised from 500 perkb to floor of 1000
2024-01-18T13:17:18.651Z DEBUG   lightningd: Adding block 128: 18b0bf4fcf69f9773522bd60b50092c17c31585004a120ca743583e23a551bc5
2024-01-18T13:17:18.651Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: Got UTXO spend for f37f8993c16b69e3c4ce1b417145054ef4f9c0cb10d797fe800f8757d5487a64:0: ce16ce33e7a722d84775df94e52ee02998de6497763c007da50237bc5b71c044
2024-01-18T13:17:18.652Z DEBUG   wallet: Owning output 1 9691526sat (SEGWIT) txid ce16ce33e7a722d84775df94e52ee02998de6497763c007da50237bc5b71c044 CONFIRMED
2024-01-18T13:17:18.654Z DEBUG   gossipd: Deleting channel 116x1x0 due to the funding outpoint being spent
2024-01-18T13:17:18.656Z DEBUG   plugin-bookkeeper: coin_move 2 (withdrawal) 0msat -9897079000msat chain_mvt 1705583838
2024-01-18T13:17:18.656Z DEBUG   plugin-bookkeeper: coin_move 2 (deposit) 9691526000msat -0msat chain_mvt 1705583838
2024-01-18T13:17:18.667Z DEBUG   lightningd: Adding block 129: 5a5dafd38efa7fb1e3fa2d703de74bbab203ea80030c247969057d0c6fe7fe24
2024-01-18T13:17:18.682Z DEBUG   lightningd: Adding block 130: 57f191e2812cf65e85e1df97c0bf8774428ada7a9fdc8ef5fdda806698fe0993
2024-01-18T13:17:18.696Z DEBUG   lightningd: Adding block 131: 389cfad1fa907d4064fdc2c0d52354cae9f3bff4d6ef9217ef630b15a0246db7
2024-01-18T13:17:18.710Z DEBUG   lightningd: Adding block 132: 3f52a54ca4eca334d6a322b8b2d937fac73d56db01b6b67a9f05977f2be6fd1f
2024-01-18T13:17:18.724Z DEBUG   lightningd: Adding block 133: 2c07119cbe449b41a32093b482dd2dda1e30be5824cda498c8163885ed2cbf18
2024-01-18T13:17:18.737Z DEBUG   lightningd: Adding block 134: 0e0761db6d58bbc02d28300d21910e4f2bbcefa8dc395158e94119f2d00451e6
2024-01-18T13:17:18.745Z DEBUG   lightningd: Got first depth change ->4294967295 for ce16ce33e7a722d84775df94e52ee02998de6497763c007da50237bc5b71c044
2024-01-18T13:17:18.745Z INFO    03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: splice_depth_cb: sending funding depth scid: 128x1x0
2024-01-18T13:17:18.746Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Current channel id is 116x1x0, splice_short_channel_id now set to 128x1x0
2024-01-18T13:17:18.746Z DEBUG   gossipd: REPLY WIRE_GOSSIPD_NEW_BLOCKHEIGHT_REPLY with 0 fds
2024-01-18T13:17:18.746Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_out WIRE_SPLICE_LOCKED
2024-01-18T13:17:18.747Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: billboard: Channel ready for use.
2024-01-18T13:17:19.086Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: peer_in WIRE_SPLICE_LOCKED
2024-01-18T13:17:19.086Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-hsmd: Got WIRE_HSMD_CHECK_OUTPOINT
2024-01-18T13:17:19.086Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: mutual splice_locked, scid LOCAL & REMOTE updated to: 128x1x0
2024-01-18T13:17:19.086Z DEBUG   hsmd: Client: Received message 32 from client
2024-01-18T13:17:19.086Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: mutual splice_locked, updating change from: { funding=102100sat, opener=LOCAL, local={ owed_local=102000000msat, owed_remote=100000msat }, remote={ owed_local=102000000msat, owed_remote=100000msat } }
2024-01-18T13:17:19.086Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-hsmd: Got WIRE_HSMD_LOCK_OUTPOINT
2024-01-18T13:17:19.086Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: mutual splice_locked, channel updated to: { funding=307100sat, opener=LOCAL, local={ owed_local=307000000msat, owed_remote=100000msat }, remote={ owed_local=307000000msat, owed_remote=100000msat } }
2024-01-18T13:17:19.086Z DEBUG   hsmd: Client: Received message 37 from client
2024-01-18T13:17:19.087Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: lightningd, splice_locked clearing inflights
2024-01-18T13:17:19.087Z INFO    03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: Short channel id changed from 116x1x0->128x1x0
2024-01-18T13:17:19.088Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: Watching for funding txid: ce16ce33e7a722d84775df94e52ee02998de6497763c007da50237bc5b71c044
2024-01-18T13:17:19.088Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: Moving channel state from CHANNELD_AWAITING_SPLICE to CHANNELD_NORMAL
2024-01-18T13:17:19.088Z INFO    03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: State changed from CHANNELD_AWAITING_SPLICE to CHANNELD_NORMAL
2024-01-18T13:17:19.088Z DEBUG   lightningd: update_feerates: feerate = 1255, min=1, max=2530, penalty=253
2024-01-18T13:17:19.088Z UNUSUAL 03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-chan#2: Can't unwatch txid ce16ce33e7a722d84775df94e52ee02998de6497763c007da50237bc5b71c044
2024-01-18T13:17:19.089Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: billboard: Channel ready for use.
2024-01-18T13:17:19.089Z DEBUG   gossipd: received private channel announcement from channeld for 128x1x0
2024-01-18T13:17:19.091Z DEBUG   plugin-bookkeeper: coin_move 2 (channel_open) 307000000msat -0msat chain_mvt 1705583839
2024-01-18T13:17:19.099Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Trying commit
2024-01-18T13:17:19.100Z DEBUG   03c5fcac4c6b9d2a0b5d489bfae7d22c69d411ddd6db663ab656516ebef13919a8-channeld-chan#2: Can't send commit: nothing to send, feechange not wanted ({ SENT_ADD_ACK_REVOCATION:1255 }) blockheight not wanted ({ SENT_ADD_ACK_REVOCATION:0 })
2024-01-18T13:17:19.158Z INFO    plugin-cmd_cln_plugin: 14:17:19 server.go:377: Received HtlcResolution correlationid:\"cln:htlc_accepted#151\"  continue:{payload:\"02040623a7c004018a0608fdb7e53ec7e85e7a\"  forward_to:\"44c0715bbc3702a57d003c769764de9829e02ee594df7547d822a7e733ce16ce\"}
2024-01-18T13:17:19.158Z DEBUG   lightningd: Plugin cmd_cln_plugin returned from htlc_accepted hook call
2024-01-18T13:17:19.158Z DEBUG   03c9e234bdd82fb1985e7ae94c3e3037546b2b4d15ebf8614ac7bb1394070b3daf-chan#1: HTLC in 1 RCVD_ADD_ACK_REVOCATION->SENT_REMOVE_HTLC
2024-01-18T13:17:19.159Z DEBUG   03c9e234bdd82fb1985e7ae94c3e3037546b2b4d15ebf8614ac7bb1394070b3daf-channeld-chan#1: FAIL:: HTLC REMOTE 1 = SENT_REMOVE_HTLC/RCVD_REMOVE_HTLC 
2024-01-18T13:17:19.159Z DEBUG   03c9e234bdd82fb1985e7ae94c3e3037546b2b4d15ebf8614ac7bb1394070b3daf-channeld-chan#1: peer_out WIRE_UPDATE_FAIL_HTLC

Using cln v23.11

JssDWt avatar Jan 18 '24 13:01 JssDWt

Closing this, because I may be mis setting the channel id in the forward_to.

JssDWt avatar Jan 18 '24 13:01 JssDWt

Reopening, now that I've verified that the forward_to is actually set to the splice channelid.

JssDWt avatar Jan 18 '24 15:01 JssDWt

There has been a lot of general fixes to splicing and routing since this issue.

Could you retest if you issue is still occuring?

ddustin avatar Jul 11 '24 18:07 ddustin

Will do in about two weeks, thanks for the ping

JssDWt avatar Jul 12 '24 15:07 JssDWt

@ddustin this still happens on 24.05. Should I check master?

JssDWt avatar Aug 02 '24 14:08 JssDWt

@ddustin I still can't get this to work with current master. Here's a log from a test. Can you see anything here why this would fail?

  • first you see the forward over a newly created channel (not a splice), this works:
2024-10-05T08:43:35.503Z INFO    plugin-lspd_cln_plugin: 2024/10/05 08:43:35 Received HtlcResolution correlationid:\"cln:htlc_accepted#137\"  continue:{payload:\"02030186a004017b06081582969225a465df\"  forward_to:\"b64f6b36263a2345a09a3fb65bb22cba4b9b23e78c4101314037a439aeaf8232\"}
2024-10-05T08:43:35.503Z DEBUG   0369170cb02e7190af82cd2574b0f035eb1b007116dc4eba74762205e50257dcc4-channeld-chan#2: NEW:: HTLC LOCAL 0 = SENT_ADD_HTLC/RCVD_ADD_HTLC 
2024-10-05T08:43:35.503Z DEBUG   0369170cb02e7190af82cd2574b0f035eb1b007116dc4eba74762205e50257dcc4-channeld-chan#2: Adding HTLC 0 amount=100000msat cltv=123 gave CHANNEL_ERR_ADD_OK
2024-10-05T08:43:35.503Z DEBUG   0369170cb02e7190af82cd2574b0f035eb1b007116dc4eba74762205e50257dcc4-channeld-chan#2: peer_out WIRE_UPDATE_ADD_HTLC
  • Then the same procedure, but over a newly spliced channel, the htlc immediately fails.
2024-10-05T08:43:43.639Z INFO    plugin-lspd_cln_plugin: 2024/10/05 08:43:43 Received HtlcResolution correlationid:\"cln:htlc_accepted#160\"  continue:{payload:\"02040623a7c0040187060800007d0000010000\"  forward_to:\"a3d4a8efc5d0a4b033c046c51aedb59e4e0f4d3aa9aa82c6fffcb8c8ae6b27c8\"}
2024-10-05T08:43:43.639Z DEBUG   02bcdd8a65d43ab11166a4cb10b214070fd324d3e50d6b9ec249d796daeb561d81-chan#1: HTLC in 1 RCVD_ADD_ACK_REVOCATION->SENT_REMOVE_HTLC
2024-10-05T08:43:43.640Z DEBUG   02bcdd8a65d43ab11166a4cb10b214070fd324d3e50d6b9ec249d796daeb561d81-channeld-chan#1: FAIL:: HTLC REMOTE 1 = SENT_REMOVE_HTLC/RCVD_REMOVE_HTLC 
2024-10-05T08:43:43.640Z DEBUG   02bcdd8a65d43ab11166a4cb10b214070fd324d3e50d6b9ec249d796daeb561d81-channeld-chan#1: peer_out WIRE_UPDATE_FAIL_HTLC

lightningd-lsp.log

JssDWt avatar Oct 05 '24 09:10 JssDWt

Thanks for the report and the log 🙏, I will take a look

ddustin avatar Oct 05 '24 20:10 ddustin

It appears to be failing because there is a pending HTLC when you execute the splice. While we have a test case that does this, it might not be comprehensive enough to catch how your node is doing it.

  1. Do you have a reference or test case demonstrating how you got into this state?
  2. Do you have the logs for the other node?

Thanks

ddustin avatar Oct 07 '24 03:10 ddustin

  1. Do you have the logs for the other node?

lightningd-breez-client.log

  1. Do you have a reference or test case demonstrating how you got into this state?
  • prereqs:
    • docker running
    • python3 installed
    • a build of lightningd
    • a build of bitcoind and bitcoin-cli
    • go installed
  • take this branch of lspd: https://github.com/breez/lspd/tree/splicing-poc
  • make release-all
  • run go test -timeout 20m -v ./itest -test.run TestLspd/CLN-lsp-CLN-client:_testSplicing --bitcoindexec /full/path/to/bitcoind --lightningdexec /full/path/to/lightningd --bitcoincliexec /full/path/to/bitcoin-cli --lspdexec /full/path/to/lspd/root/dir/lspd --clnpluginexec /full/path/to/lspd/root/dir/lspd_cln_plugin --testdir /full/path/to/chosen/testdir --preservelogs Optionally add --preservestate to preserve the lightningd states.

Let me know whether that works for you, I'll be glad to help.

JssDWt avatar Oct 07 '24 07:10 JssDWt

Another option is to run the tests in CI, let me know whether that is preferred @ddustin

JssDWt avatar Oct 07 '24 07:10 JssDWt

Can you point me to the file that's making the test happen and / or describe it in steps? I'd like to recreate however you're doing it in the CLN CI tests. Thanks 🙏

ddustin avatar Oct 07 '24 21:10 ddustin

Can you point me to the file that's making the test happen and / or describe it in steps? I'd like to recreate however you're doing it in the CLN CI tests. Thanks 🙏

This is the test: https://github.com/breez/lspd/blob/splicing-poc/itest/splicing_test.go

What happens is:

  • Sender is connected to LSP
  • Sender pays invoice with route hint to LSP, but LSP does not have a channel yet
  • LSP intercepts the HTLC
  • LSP opens zero conf channel to recipient
  • LSP forwards HTLC over new channel

Then splicing part, same procedure as above, but LSP already has channel, so performs a splice

  • Sender is connected to LSP
  • Sender pays invoice with route hint to LSP, LSP has channel to recipient
  • LSP intercepts the HTLC
  • LSP splices additional liquidity into the recipient channel
  • LSP forwards HTLC over new channel

Intercept logic from LSP here https://github.com/breez/lspd/blob/splicing-poc/interceptor/intercept_handler.go rewriting the onion to the new destination here https://github.com/breez/lspd/blob/splicing-poc/cln/cln_interceptor.go#L206-L232

JssDWt avatar Oct 08 '24 11:10 JssDWt

@ddustin Let me know if there's anything I can do to help with this!

JssDWt avatar Oct 14 '24 07:10 JssDWt

@ddustin any updates on this?

JssDWt avatar Mar 03 '25 08:03 JssDWt

  • LSP opens zero conf channel to recipient

Ah yes this is the specific issue. Splicing hasn't been tested on zero-conf channels.

ddustin avatar Aug 16 '25 14:08 ddustin

Ah yes this is the specific issue. Splicing hasn't been tested on zero-conf channels.

In the test I let the splice confirm before forwarding the htlc, so that shouldn't be it.

JssDWt avatar Aug 16 '25 20:08 JssDWt

Hm, yeah I see in your log you do let it confirm.

We have many tests that do payments after a splice.

These tests do payments after a splice:

  • test_splice
  • test_two_chan_splice_in
  • test_splice_rbf
  • test_splice_out
  • test_invalid_splice
  • test_commit_crash_splice
  • test_splice_disconnect_sig

And recently:

  • test_route_by_old_scid

Another idea is the payment is routing by the old scid, in which case the recently added test covers that and I believe Rusty fixed an issue related to that.

Without more information I can't see what's specific about your test over the built in CLN tests for this. Unless its the zero-conf into confirmed splice that's throwing it off 🤔

ddustin avatar Aug 18 '25 20:08 ddustin