CI flake `test_payment_duplicate_uncommitted`

Start with tests/test_pay.py::test_payment_duplicate_uncommitted and reproduce the failure around the concurrent xpay calls, listsendpays check, and dev_reenable_commit. Compare the expected in-progress RpcError with the observed successful-payment error; done means the test reliably exercises the duplicate-uncommitted case and passes without CI flakiness.

 def test_payment_duplicate_uncommitted(node_factory, executor):
        # We want to test two payments at the same time, before we send commit
        l1 = node_factory.get_node(options={'dev-disable-commit-after': 0})
        l2 = node_factory.get_node()
    
        l1.rpc.connect(l2.info['id'], 'localhost', l2.port)
    
        l1.fundchannel(l2, 100000)
    
        inv1 = l2.rpc.invoice(1000, 'inv1', 'inv1')
    
        # Start first payment, but not yet in db.
        fut = executor.submit(l1.rpc.xpay, inv1['bolt11'])
    
        # Make sure that's started...
        l1.daemon.wait_for_log('peer_out WIRE_UPDATE_ADD_HTLC')
    
        # We should see it in listsendpays
        payments = l1.rpc.listsendpays()['payments']
        assert len(payments) == 1
        assert payments[0]['status'] == 'pending' and payments[0]['payment_hash'] == inv1['payment_hash']
    
        # Second one will be stopped.
        fut2 = executor.submit(l1.rpc.xpay, inv1['bolt11'])
    
        # Now, let it commit.
        l1.rpc.dev_reenable_commit(l2.info['id'])
    
        # First should succeed, second should be denied.
        fut.result(TIMEOUT)
        with pytest.raises(RpcError, match="Payment with groupid=[0-9]* still in progress, cannot retry before that completes"):
>           fut2.result(TIMEOUT)

tests/test_pay.py:469: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/opt/hostedtoolcache/Python/3.10.21/x64/lib/python3.10/concurrent/futures/_base.py:458: in result
    return self.__get_result()
/opt/hostedtoolcache/Python/3.10.21/x64/lib/python3.10/concurrent/futures/_base.py:403: in __get_result
    raise self._exception
/opt/hostedtoolcache/Python/3.10.21/x64/lib/python3.10/concurrent/futures/thread.py:58: in run
    result = self.fn(*self.args, **self.kwargs)
contrib/pyln-client/pyln/client/lightning.py:1206: in xpay
    return self.call("xpay", payload)
contrib/pyln-testing/pyln/testing/utils.py:1034: in call
    res = LightningRpc.call(self, method, payload, cmdprefix, filter)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <pyln.testing.utils.PrettyPrintingLightningRpc object at 0x7fcddc7245b0>
method = 'xpay'
payload = {'invstring': 'lnbcrt10n1p426yf4sp5fd95u543vxzp96gngc4nejqmfnr4kvqr5kx3u2drdtjuwzz233tspp5j2te076xdlk6kyge0nrdrx20knv5lgxnpgejevjse8es5ta2nnrsdq8d9h8vvgxqyjw5qcqp99qxpqysgqut5lnp4ptadn82rneg3gwarwpwg4fayrvz8czl2nuq2z2c8aezt3dp69r4fpacgxzfcwrz6azcndaqg2s4ryjhgwsc94erjjy20u87gpgzad9x'}
cmdprefix = None, filter = None

    def call(self, method, payload=None, cmdprefix=None, filter=None):
        """Generic call API: you can set cmdprefix here, or set self.cmdprefix
        before the call is made.
    
        """
        self.logger.debug("Calling %s with payload %r", method, payload)
    
        if payload is None:
            payload = {}
        # Filter out arguments that are None
        if isinstance(payload, dict):
            payload = {k: v for k, v in payload.items() if v is not None}
    
        this_id = self.get_json_id(method, cmdprefix)
        self.next_id += 1
    
        # FIXME: we open a new socket for every readobj call...
        sock = UnixSocket(self.socket_path)
    
        buf = b''
    
        if self._notify is not None:
            # Opt into the notifications support
            self._writeobj(sock, {
                "jsonrpc": "2.0",
                "method": "notifications",
                "id": this_id + "+notify-enable",
                "params": {
                    "enable": True
                },
            })
            # FIXME: Notification schema support?
            _, buf = self._readobj(sock, buf)
    
        request = {
            "jsonrpc": "2.0",
            "method": method,
            "params": payload,
            "id": this_id,
        }
    
        if filter is None:
            filter = self._filter
        if filter is not None:
            request["filter"] = filter
    
        self._writeobj(sock, request)
        while True:
            resp, buf = self._readobj(sock, buf)
            id = resp.get("id", None)
            meth = resp.get("method", None)
    
            if meth == 'message' and self._notify is not None:
                n = resp['params']
                self._notify(
                    message=n.get('message', None),
                    progress=n.get('progress', None),
                    request=request
                )
                continue
    
            if meth is None or id is None:
                break
    
        self.logger.debug("Received response for %s call: %r", method, resp)
        if 'id' in resp and resp['id'] != this_id:
            raise ValueError("Malformed response, id is not {}: {}.".format(this_id, resp))
        sock.close()
    
        if not isinstance(resp, dict):
            raise TypeError("Malformed response, response is not a dictionary %s." % resp)
        elif "error" in resp:
>           raise RpcError(method, payload, resp['error'])
E           pyln.client.lightning.RpcError: RPC call failed: method: xpay, payload: {'invstring': 'lnbcrt10n1p426yf4sp5fd95u543vxzp96gngc4nejqmfnr4kvqr5kx3u2drdtjuwzz233tspp5j2te076xdlk6kyge0nrdrx20knv5lgxnpgejevjse8es5ta2nnrsdq8d9h8vvgxqyjw5qcqp99qxpqysgqut5lnp4ptadn82rneg3gwarwpwg4fayrvz8czl2nuq2z2c8aezt3dp69r4fpacgxzfcwrz6azcndaqg2s4ryjhgwsc94erjjy20u87gpgzad9x'}, error: {'code': 219, 'message': 'Already paid this invoice successfully'}

contrib/pyln-client/pyln/client/lightning.py:428: RpcError

During handling of the above exception, another exception occurred:

node_factory = <pyln.testing.utils.NodeFactory object at 0x7fcddc7258a0>
executor = <concurrent.futures.thread.ThreadPoolExecutor object at 0x7fcddc726350>

    def test_payment_duplicate_uncommitted(node_factory, executor):
        # We want to test two payments at the same time, before we send commit
        l1 = node_factory.get_node(options={'dev-disable-commit-after': 0})
        l2 = node_factory.get_node()
    
        l1.rpc.connect(l2.info['id'], 'localhost', l2.port)
    
        l1.fundchannel(l2, 100000)
    
        inv1 = l2.rpc.invoice(1000, 'inv1', 'inv1')
    
        # Start first payment, but not yet in db.
        fut = executor.submit(l1.rpc.xpay, inv1['bolt11'])
    
        # Make sure that's started...
        l1.daemon.wait_for_log('peer_out WIRE_UPDATE_ADD_HTLC')
    
        # We should see it in listsendpays
        payments = l1.rpc.listsendpays()['payments']
        assert len(payments) == 1
        assert payments[0]['status'] == 'pending' and payments[0]['payment_hash'] == inv1['payment_hash']
    
        # Second one will be stopped.
        fut2 = executor.submit(l1.rpc.xpay, inv1['bolt11'])
    
        # Now, let it commit.
        l1.rpc.dev_reenable_commit(l2.info['id'])
    
        # First should succeed, second should be denied.
        fut.result(TIMEOUT)
>       with pytest.raises(RpcError, match="Payment with groupid=[0-9]* still in progress, cannot retry before that completes"):
E       AssertionError: Regex pattern did not match.
E         Expected regex: 'Payment with groupid=[0-9]* still in progress, cannot retry before that completes'
E         Actual message: "RPC call failed: method: xpay, payload: {'invstring': 'lnbcrt10n1p426yf4sp5fd95u543vxzp96gngc4nejqmfnr4kvqr5kx3u2drdtjuwzz233tspp5j2te076xdlk6kyge0nrdrx20knv5lgxnpgejevjse8es5ta2nnrsdq8d9h8vvgxqyjw5qcqp99qxpqysgqut5lnp4ptadn82rneg3gwarwpwg4fayrvz8czl2nuq2z2c8aezt3dp69r4fpacgxzfcwrz6azcndaqg2s4ryjhgwsc94erjjy20u87gpgzad9x'}, error: {'code': 219, 'message': 'Already paid this invoice successfully'}"

tests/test_pay.py:468: AssertionError

lightningd-2 2026-09-18T10:23:49.584Z DEBUG   plugin-chanbackup: Updated `emergency.recover` state after receiving new commitment secret.
lightningd-2 2026-09-18T10:23:49.585Z TRACE   lightningd: Plugin offers returned from invoice_payment hook call
lightningd-2 2026-09-18T10:23:49.586Z INFO    lightningd: Resolved invoice 'inv1' with amount 1000msat in 1 htlcs
lightningd-2 2026-09-18T10:23:49.586Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-chan#1: HTLC in 0 RCVD_ADD_ACK_REVOCATION->SENT_REMOVE_HTLC
lightningd-2 2026-09-18T10:23:49.587Z DEBUG   plugin-chanbackup: Updating the SCB
lightningd-2 2026-09-18T10:23:49.587Z DEBUG   plugin-chanbackup: Updating the SCB file...
lightningd-1 2026-09-18T10:23:49.589Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-connectd: peer_in WIRE_PEER_STORAGE
lightningd-2 2026-09-18T10:23:49.589Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: FULFILL:: HTLC REMOTE 0 = SENT_REMOVE_HTLC/RCVD_REMOVE_HTLC FULFILLED
lightningd-2 2026-09-18T10:23:49.589Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: peer_out WIRE_UPDATE_FULFILL_HTLC
lightningd-2 2026-09-18T10:23:49.589Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: Trying commit
lightningd-2 2026-09-18T10:23:49.589Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: htlc 0: SENT_REMOVE_HTLC->SENT_REMOVE_COMMIT
lightningd-2 2026-09-18T10:23:49.589Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: htlc added REMOTE: local 0 remote 99999000
lightningd-2 2026-09-18T10:23:49.589Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: -> local 1000 remote 99999000
lightningd-1 2026-09-18T10:23:49.589Z TRACE   lightningd: Calling custommsg hook of plugin chanbackup
lightningd-2 2026-09-18T10:23:49.589Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: sending_commit: HTLC REMOTE 0 = SENT_REMOVE_COMMIT/RCVD_REMOVE_COMMIT FULFILLED
lightningd-2 2026-09-18T10:23:49.589Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: send_commit_part(splice: 0, remote_splice: 0, index: 2)
lightningd-2 2026-09-18T10:23:49.590Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: channel->view[REMOTE].owed[REMOTE] 99999sat; channel->view[REMOTE].owed[LOCAL] 1sat; channel->view[LOCAL].owed[REMOTE] 99999sat; channel->view[LOCAL].owed[LOCAL] 0sat;
lightningd-2 2026-09-18T10:23:49.590Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: calc_commitsigs(0x504000000178, 0x5190000000a8, 0x50400001cbb8, 0x50b000005de8, 0x5060000046c8, 2, 0x519000000144, 0x7f0861901140)
lightningd-2 2026-09-18T10:23:49.590Z TRACE   plugin-chanbackup: Peer storage sent!
lightningd-2 2026-09-18T10:23:49.590Z TRACE   lightningd: Plugin chanbackup returned from commitment_revocation hook call
lightningd-2 2026-09-18T10:23:49.590Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-connectd: peer_out WIRE_PEER_STORAGE
lightningd-2 2026-09-18T10:23:49.591Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: Creating commit_sig signature 2 3044022001dacf1431fde3ae6463a49efe2f6b13f2378f39ce278477c2b4f44d29df5b0e022065726ef95c33560de11ec3549d46c446935add962605822408f0debad836fd3901 for tx 02000000017ec561926671ad820476660de3b180fcb9dbe00574b059cc543d10f607b8c16f00000000005d0eb580024a01000000000000220020515beb78b1125911558a77ff7a71d76daf576ea6490d4e1ac2e9e9fc6a4290ef8f73010000000000220020d91f8400e8803f976457b8dd73ff7ebe7d0b8a8061159319f209c6b424b08529325b0020 wscript 522102096e74aff8b917448bf683a9e60058194a77bfea42360f8ad2434763dd63527c21025b93ec4849eec35a35063a7e449c22a85940ececea6d0f40723f7b5f5afc9b6852ae key 025b93ec4849eec35a35063a7e449c22a85940ececea6d0f40723f7b5f5afc9b68
lightningd-2 2026-09-18T10:23:49.592Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: Telling master we're about to commit...
lightningd-2 2026-09-18T10:23:49.592Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: Sending master 1020
lightningd-2 2026-09-18T10:23:49.592Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-chan#1: HTLC in 0 SENT_REMOVE_HTLC->SENT_REMOVE_COMMIT
lightningd-2 2026-09-18T10:23:49.598Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: ... , awaiting 1120
lightningd-2 2026-09-18T10:23:49.598Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-hsmd: Got WIRE_HSMD_SIGN_REMOTE_COMMITMENT_TX
lightningd-2 2026-09-18T10:23:49.598Z DEBUG   hsmd: Client: Received message 19 from client
lightningd-2 2026-09-18T10:23:49.598Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: Got it!
lightningd-2 2026-09-18T10:23:49.598Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: Sending commit_sig with 0 htlc sigs
lightningd-2 2026-09-18T10:23:49.598Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: peer_out WIRE_COMMITMENT_SIGNED
lightningd-1 2026-09-18T10:23:49.599Z TRACE   lightningd: Plugin chanbackup returned from custommsg hook call
lightningd-1 2026-09-18T10:23:49.600Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-connectd: custommsg processing finished
lightningd-1 2026-09-18T10:23:49.601Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-connectd: peer_in UNKNOWN 2111
lightningd-1 2026-09-18T10:23:49.601Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: peer_in WIRE_UPDATE_FULFILL_HTLC
lightningd-1 2026-09-18T10:23:49.601Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: FULFILL:: HTLC LOCAL 0 = RCVD_REMOVE_HTLC/SENT_REMOVE_HTLC FULFILLED
lightningd-1 2026-09-18T10:23:49.601Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: peer_in WIRE_COMMITMENT_SIGNED
lightningd-1 2026-09-18T10:23:49.601Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: fromwire_commitment_signed(0x50f000024698) primary
lightningd-1 2026-09-18T10:23:49.601Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: handle_peer_commit_sig(splice: 0, remote_splice: 0, commit_index: 0, local_index: 2, msg: 0x50f000024698)
lightningd-1 2026-09-18T10:23:49.601Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Received commit
lightningd-1 2026-09-18T10:23:49.601Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: htlc 0: RCVD_REMOVE_HTLC->RCVD_REMOVE_COMMIT
lightningd-1 2026-09-18T10:23:49.602Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: htlc added LOCAL: local 99999000 remote 0
lightningd-1 2026-09-18T10:23:49.602Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: -> local 99999000 remote 1000
lightningd-1 2026-09-18T10:23:49.602Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: rcvd_commit: HTLC LOCAL 0 = RCVD_REMOVE_COMMIT/SENT_REMOVE_COMMIT FULFILLED
lightningd-1 2026-09-18T10:23:49.602Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: channel->view[REMOTE].owed[REMOTE] 0sat; channel->view[REMOTE].owed[LOCAL] 99999sat; channel->view[LOCAL].owed[REMOTE] 1sat; channel->view[LOCAL].owed[LOCAL] 99999sat;
lightningd-1 2026-09-18T10:23:49.603Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Derived key 03b1b0b5c353a1fd3829964d3044426f600eae49aa0f26f1a621e1b64af7dd564a from basepoint 03da233776bc38dc3d15a2b9a478ef126d168bdaf4f34a43fca659d36f60491fe6, point 03bd5c6300a962f1bc9d997c39c2bb9ab91afde5a05aef8f063e554eb167966551
lightningd-1 2026-09-18T10:23:49.604Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Received commit_sig with 0 htlc sigs
lightningd-1 2026-09-18T10:23:49.604Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-hsmd: Got WIRE_HSMD_VALIDATE_COMMITMENT_TX
lightningd-1 2026-09-18T10:23:49.604Z DEBUG   hsmd: Client: Received message 35 from client
lightningd-1 2026-09-18T10:23:49.605Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Sending revoke_and_ack
lightningd-1 2026-09-18T10:23:49.606Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: htlc 0: RCVD_REMOVE_COMMIT->SENT_REMOVE_REVOCATION
lightningd-1 2026-09-18T10:23:49.606Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: sending_revoke_and_ack: HTLC LOCAL 0 = SENT_REMOVE_REVOCATION/RCVD_REMOVE_REVOCATION FULFILLED
lightningd-1 2026-09-18T10:23:49.606Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: revoke_and_ack made pending: commit timer
lightningd-1 2026-09-18T10:23:49.606Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Sending master 1021
lightningd-1 2026-09-18T10:23:49.607Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-chan#1: got commitsig 2: feerate 3755, blockheight: 0, 0 added, 1 fulfilled, 0 failed, 0 changed. 0 splice commitments.
lightningd-1 2026-09-18T10:23:49.607Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-chan#1: HTLC out 0 SENT_ADD_ACK_REVOCATION->RCVD_REMOVE_COMMIT
lightningd-1 2026-09-18T10:23:49.608Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-chan#1: HTLC out 0 RCVD_REMOVE_COMMIT->SENT_REMOVE_REVOCATION
lightningd-2 2026-09-18T10:23:49.608Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: Can't send commit: waiting for revoke_and_ack
lightningd-1 2026-09-18T10:23:49.611Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: ... , awaiting 1121
lightningd-1 2026-09-18T10:23:49.613Z DEBUG   plugin-cln-askrene: notify msg debug: get_routes completed in 77 ms
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: notify msg info: ->033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a: Success: preimage=6d635605eeceffdee0121ac2877de135db549e4f039e29c23c83e488252285cc
lightningd-1 2026-09-18T10:23:49.616Z INFO    plugin-cln-xpay: 1: ->033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a: Success: preimage=6d635605eeceffdee0121ac2877de135db549e4f039e29c23c83e488252285cc
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: notify msg debug: getroutes_done: continuing
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: 3: getroutes_done: continuing
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: notify msg debug: routes for 1000msat = {"probability_ppm":1000000,"routes":[{"probability_ppm":1000000,"amount_msat":1000,"final_cltv":5,"path":[{"short_channel_id_dir":"103x1x0/1","node_id_in":"038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b","node_id_out":"033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a","amount_in_msat":1000,"amount_out_msat":1000,"cltv_in":5,"cltv_out":5}]}]}
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: 3: routes for 1000msat = {"probability_ppm":1000000,"routes":[{"probability_ppm":1000000,"amount_msat":1000,"final_cltv":5,"path":[{"short_channel_id_dir":"103x1x0/1","node_id_in":"038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b","node_id_out":"033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a","amount_in_msat":1000,"amount_out_msat":1000,"cltv_in":5,"cltv_out":5}]}]}
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: notify msg debug: shadow #0: stopping
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: 3: shadow #0: stopping
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: notify msg debug: ->033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a: doing askrene-reserve
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: 3: ->033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a: doing askrene-reserve
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: notify msg debug: waiting...
lightningd-1 2026-09-18T10:23:49.616Z DEBUG   plugin-cln-xpay: 3: waiting...
lightningd-1 2026-09-18T10:23:49.620Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Got it!
lightningd-1 2026-09-18T10:23:49.620Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: peer_out WIRE_REVOKE_AND_ACK
lightningd-1 2026-09-18T10:23:49.620Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Trying commit
lightningd-1 2026-09-18T10:23:49.620Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: htlc 0: SENT_REMOVE_REVOCATION->SENT_REMOVE_ACK_COMMIT
lightningd-1 2026-09-18T10:23:49.620Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: htlc added REMOTE: local 99999000 remote 0
lightningd-1 2026-09-18T10:23:49.620Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: -> local 99999000 remote 1000
lightningd-1 2026-09-18T10:23:49.620Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: sending_commit: HTLC LOCAL 0 = SENT_REMOVE_ACK_COMMIT/RCVD_REMOVE_ACK_COMMIT FULFILLED
lightningd-1 2026-09-18T10:23:49.620Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: send_commit_part(splice: 0, remote_splice: 0, index: 2)
lightningd-1 2026-09-18T10:23:49.620Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: channel->view[REMOTE].owed[REMOTE] 1sat; channel->view[REMOTE].owed[LOCAL] 99999sat; channel->view[LOCAL].owed[REMOTE] 1sat; channel->view[LOCAL].owed[LOCAL] 99999sat;
lightningd-1 2026-09-18T10:23:49.620Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: calc_commitsigs(0x504000000178, 0x5190000000a8, 0x504000022178, 0x50b000007338, 0x506000005748, 2, 0x519000000144, 0x7f4afe301540)
lightningd-1 2026-09-18T10:23:49.621Z DEBUG   plugin-cln-renepay: sendpay_success notification: {"sendpay_success":{"created_index":1,"id":1,"payment_hash":"929797fb466fedab11197cc6d1994fb4d94fa0d30a332cb250c9f30a2faa9cc7","groupid":5374195485592546236,"updated_index":1,"partid":1,"destination":"033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a","amount_msat":1000,"amount_sent_msat":1000,"created_at":1789727029,"completed_at":1789727029,"status":"complete","payment_preimage":"6d635605eeceffdee0121ac2877de135db549e4f039e29c23c83e488252285cc","bolt11":"lnbcrt10n1p426yf4sp5fd95u543vxzp96gngc4nejqmfnr4kvqr5kx3u2drdtjuwzz233tspp5j2te076xdlk6kyge0nrdrx20knv5lgxnpgejevjse8es5ta2nnrsdq8d9h8vvgxqyjw5qcqp99qxpqysgqut5lnp4ptadn82rneg3gwarwpwg4fayrvz8czl2nuq2z2c8aezt3dp69r4fpacgxzfcwrz6azcndaqg2s4ryjhgwsc94erjjy20u87gpgzad9x"}}
lightningd-2 2026-09-18T10:23:49.622Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: peer_in WIRE_REVOKE_AND_ACK
lightningd-2 2026-09-18T10:23:49.622Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: Received revoke_and_ack
lightningd-2 2026-09-18T10:23:49.622Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: htlc 0: SENT_REMOVE_COMMIT->RCVD_REMOVE_REVOCATION
lightningd-2 2026-09-18T10:23:49.622Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: rcvd_revoke_and_ack: HTLC REMOTE 0 = RCVD_REMOVE_REVOCATION/SENT_REMOVE_REVOCATION FULFILLED
lightningd-1 2026-09-18T10:23:49.622Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-hsmd: Got WIRE_HSMD_REVOKE_COMMITMENT_TX
lightningd-2 2026-09-18T10:23:49.622Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: Commits outstanding after recv revoke_and_ack
lightningd-1 2026-09-18T10:23:49.622Z DEBUG   hsmd: Client: Received message 40 from client
lightningd-2 2026-09-18T10:23:49.622Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: HTLC 0[REMOTE] => RCVD_REMOVE_REVOCATION
lightningd-1 2026-09-18T10:23:49.622Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-hsmd: Got WIRE_HSMD_SIGN_REMOTE_COMMITMENT_TX
lightningd-2 2026-09-18T10:23:49.623Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-hsmd: Got WIRE_HSMD_VALIDATE_REVOCATION
lightningd-1 2026-09-18T10:23:49.623Z DEBUG   hsmd: Client: Received message 19 from client
lightningd-2 2026-09-18T10:23:49.623Z DEBUG   hsmd: Client: Received message 36 from client
lightningd-2 2026-09-18T10:23:49.623Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-hsmd: Got WIRE_HSMD_SIGN_PENALTY_TO_US
lightningd-2 2026-09-18T10:23:49.623Z DEBUG   hsmd: Client: Received message 14 from client
lightningd-1 2026-09-18T10:23:49.623Z TRACE   plugin-cln-askrene: json_askrene_unreserve called: {"path":[{"short_channel_id_dir":"103x1x0/1","amount_msat":1000,"layer":"xpay-1"}]}
lightningd-1 2026-09-18T10:23:49.623Z TRACE   plugin-cln-askrene: json_askrene_reserve called: {"path":[{"short_channel_id_dir":"103x1x0/1","amount_msat":1000,"layer":"xpay-3"}]}
lightningd-1 2026-09-18T10:23:49.623Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Creating commit_sig signature 2 30440220499faf48c48e0db4b5607a45ab62485d2b79f4e1e368dba612a2251fbd0bec0c022060461baa6f70f85462fd80db9f5912a8c2e47543a9f0e7c554f08d3c4b8e7dbb01 for tx 02000000017ec561926671ad820476660de3b180fcb9dbe00574b059cc543d10f607b8c16f00000000005d0eb580024a01000000000000220020515beb78b1125911558a77ff7a71d76daf576ea6490d4e1ac2e9e9fc6a4290ef8f730100000000002200205936acdb20a3b4f1aff5070e01a60e3c6c3dd07b4bb412e423c3ffab58582c2c325b0020 wscript 522102096e74aff8b917448bf683a9e60058194a77bfea42360f8ad2434763dd63527c21025b93ec4849eec35a35063a7e449c22a85940ececea6d0f40723f7b5f5afc9b6852ae key 02096e74aff8b917448bf683a9e60058194a77bfea42360f8ad2434763dd63527c
lightningd-1 2026-09-18T10:23:49.623Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Telling master we're about to commit...
lightningd-1 2026-09-18T10:23:49.623Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Sending master 1020
lightningd-1 2026-09-18T10:23:49.623Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-chan#1: HTLC out 0 SENT_REMOVE_REVOCATION->SENT_REMOVE_ACK_COMMIT
lightningd-2 2026-09-18T10:23:49.625Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: Sending master 1022
lightningd-2 2026-09-18T10:23:49.625Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-chan#1: got revoke 1: 1 changed
lightningd-2 2026-09-18T10:23:49.625Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-chan#1: HTLC in 0 SENT_REMOVE_COMMIT->RCVD_REMOVE_REVOCATION
lightningd-1 2026-09-18T10:23:49.625Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: ... , awaiting 1120
lightningd-2 2026-09-18T10:23:49.627Z TRACE   lightningd: Calling commitment_revocation hook of plugin chanbackup
lightningd-1 2026-09-18T10:23:49.627Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Got it!
lightningd-1 2026-09-18T10:23:49.627Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: Sending commit_sig with 0 htlc sigs
lightningd-1 2026-09-18T10:23:49.628Z DEBUG   033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a-channeld-chan#1: peer_out WIRE_COMMITMENT_SIGNED
lightningd-1 2026-09-18T10:23:49.628Z DEBUG   plugin-cln-xpay: notify msg debug: ->033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a: Reserve done!
lightningd-1 2026-09-18T10:23:49.628Z DEBUG   plugin-cln-xpay: 3: ->033845802d25b4e074ccfd7cd8b339a41dc75bf9978a034800444b51d42b07799a: Reserve done!
lightningd-1 2026-09-18T10:23:49.631Z DEBUG   lightningd: Payment: 1000msat COMPLETE
lightningd-2 2026-09-18T10:23:49.634Z DEBUG   038194b5f32bdf0aa59812c86c4ef7ad2f294104fa027d1ace9b469bb6f88cf37b-channeld-chan#1: ... , awaiting 1122
{'run_id': 359280813928685568, 'github_repository': 'ElementsProject/lightning', 'github_sha': 'efda3ee927e37dc8f8e8f9ed1a7583cf5c34937f', 'github_ref': 'refs/pull/9518/merge', 'github_ref_name': 'HEAD', 'github_run_id': 35332268133, 'github_head_ref': 'fix-eager-recover-dcs', 'github_run_number': 17931, 'github_base_ref': 'master', 'github_run_attempt': '1', 'testname': 'test_payment_duplicate_uncommitted', 'start_time': 1789727022, 'end_time': 1789727029, 'outcome': 'fail'}

https://github.com/ElementsProject/lightning/actions/runs/35332268133/job/105562941961?pr=9518