pytest: test xpay gracefully handles failure after success.

We can create this scenario by having one path force close.  We take
the opportunity to log this, even in non-slow-mode, since it's interesting
(not our bug, but someone just lost money!).

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
This commit is contained in:
Rusty Russell 2025-02-21 09:35:26 +10:30 committed by Alex Myers
parent f168cb5949
commit 43e59a6774
2 changed files with 97 additions and 9 deletions

View file

@ -519,6 +519,21 @@ static const char *describe_scidd(struct attempt *attempt, size_t index)
return fmt_short_channel_id_dir(tmpctx, &scidd);
}
/* How much did previous successes deliver? */
static struct amount_msat total_delivered(const struct payment *payment)
{
struct amount_msat sum = AMOUNT_MSAT(0);
struct attempt *attempt;
list_for_each(&payment->past_attempts, attempt, list) {
if (!attempt->preimage)
continue;
if (!amount_msat_accumulate(&sum, attempt->delivers))
abort();
}
return sum;
}
static void update_knowledge_from_error(struct command *aux_cmd,
const char *buf,
const jsmntok_t *error,
@ -531,7 +546,7 @@ static void update_knowledge_from_error(struct command *aux_cmd,
int index;
enum onion_wire failcode;
bool from_final;
const char *failcode_name, *errmsg;
const char *failcode_name, *errmsg, *description;
enum jsonrpc_errcode ecode;
tok = json_get_member(buf, error, "code");
@ -574,6 +589,7 @@ static void update_knowledge_from_error(struct command *aux_cmd,
/* Garbled? Blame random hop. */
if (!replymsg) {
index = pseudorand(tal_count(attempt->hops));
description = "Garbled error message";
add_result_summary(attempt, LOG_UNUSUAL,
"We got a garbled error message, and chose to (randomly) to disable %s for this payment",
describe_scidd(attempt, index));
@ -609,13 +625,14 @@ static void update_knowledge_from_error(struct command *aux_cmd,
} else
errmsg = failcode_name;
attempt_debug(attempt,
"Error %s for path %s, from %s",
errmsg,
fmt_path(tmpctx, attempt),
from_final ? "destination"
: index == 0 ? "local node"
: fmt_pubkey(tmpctx, &attempt->hops[index-1].next_node));
description = tal_fmt(tmpctx,
"Error %s for path %s, from %s",
errmsg,
fmt_path(tmpctx, attempt),
from_final ? "destination"
: index == 0 ? "local node"
: fmt_pubkey(tmpctx, &attempt->hops[index-1].next_node));
attempt_debug(attempt, "%s", description);
/* Final node sent an error */
if (from_final) {
@ -735,7 +752,7 @@ disable_channel:
attempt->hops[index].scidd);
json_add_bool(req->js, "enabled", false);
send_payment_req(aux_cmd, attempt->payment, req);
return;
goto check_previous_success;
channel_capacity:
req = payment_ignored_req(aux_cmd, attempt, "askrene-inform-channel");
@ -747,6 +764,21 @@ channel_capacity:
json_add_amount_msat(req->js, "amount_msat", attempt->hops[index].amount_out);
json_add_string(req->js, "inform", "constrained");
send_payment_req(aux_cmd, attempt->payment, req);
check_previous_success:
/* If they give us the preimage but we didn't succeed in giving them
* all the money, that's a win for us. But either the destination is
* buggy, or someone along the way lost money! */
if (any_attempts_succeeded(attempt->payment)) {
payment_log(attempt->payment, LOG_UNUSUAL,
"Destination accepted partial payment,"
" failed a part (%s), but accepted only %s of %s."
" Winning?!",
description,
fmt_amount_msat(tmpctx,
total_delivered(attempt->payment)),
fmt_amount_msat(tmpctx, attempt->payment->amount));
}
}
static struct command_result *unreserve_path(struct command *aux_cmd,

View file

@ -8,6 +8,7 @@ from utils import (
import os
import pytest
import re
import subprocess
import sys
from hashlib import sha256
@ -710,3 +711,58 @@ def test_xpay_slow_mode(node_factory, bitcoind):
'amount_sent_msat': 500010002,
'failed_parts': 0,
'successful_parts': 2}
@pytest.mark.parametrize("slow_mode", [False, True])
def test_fail_after_success(node_factory, bitcoind, executor, slow_mode):
# l1 -> l2 -> l3 -> l5
# \-> l4 -/^
l1, l2, l3, l4, l5 = node_factory.get_nodes(5, opts=[{'xpay-slow-mode': slow_mode},
{},
{},
{'disconnect': ['-WIRE_UPDATE_FULFILL_HTLC']},
{}])
node_factory.join_nodes([l2, l3, l5])
node_factory.join_nodes([l2, l4, l5])
# Make sure l1 can see all paths.
node_factory.join_nodes([l1, l2])
bitcoind.generate_block(5)
wait_for(lambda: len(l1.rpc.listchannels()['channels']) == 10)
inv = l5.rpc.invoice(500000000, 'test_xpay_slow_mode', 'test_xpay_slow_mode', preimage='00' * 32)['bolt11']
fut = executor.submit(l1.rpc.xpay, invstring=inv, retry_for=0)
# Part via l3 is fine. Part via l4 is stuck, so we kill l4 and mine
# blocks to make l2 force close.
l4.daemon.wait_for_log('dev_disconnect: -WIRE_UPDATE_FULFILL_HTLC')
l4.stop()
# Normally, we return as soon as first part succeeds.
if slow_mode is False:
assert fut.result(TIMEOUT) == {'payment_preimage': '00' * 32,
'amount_msat': 500000000,
'amount_sent_msat': 500010002,
'failed_parts': 0,
'successful_parts': 2}
# Time it out, l2 will collect it.
bitcoind.generate_block(13)
l2.daemon.wait_for_log('Peer permanent failure in CHANNELD_NORMAL: Offered HTLC 0 SENT_ADD_ACK_REVOCATION cltv 124 hit deadline')
bitcoind.generate_block(3, wait_for_mempool=1)
l1.daemon.wait_for_log(r"UNUSUAL.*Destination accepted partial payment, failed a part \(Error permanent_channel_failure for path ->022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59->0382ce59ebf18be7d84677c2e35f23294b9992ceca95491fcf8a56c6cb2d9de199->032cf15d1ad9c4a08d26eab1918f732d8ef8fdc6abb9640bf3db174372c491304e, from 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59\)")
# Could be either way around, check both
line = l1.daemon.is_in_log(r"UNUSUAL.*Destination accepted partial payment, failed a part")
assert re.search(r'but accepted only 32000msat of 500000000msat\. Winning\?!', line) or re.search(r'but accepted only 499968000msat of 500000000msat\. Winning\?!', line)
if slow_mode is True:
# Now it succeeds, but notes that it only sent one part!
res = fut.result(TIMEOUT)
# Some variation due to floating point.
assert res['amount_sent_msat'] < 500000000
assert res == {'payment_preimage': '00' * 32,
'amount_msat': 500000000,
'amount_sent_msat': res['amount_sent_msat'],
'failed_parts': 1,
'successful_parts': 1}