diff --git a/plugins/askrene/layer.c b/plugins/askrene/layer.c index 4e914f46581f..2875a003aad3 100644 --- a/plugins/askrene/layer.c +++ b/plugins/askrene/layer.c @@ -967,6 +967,17 @@ const struct node_bias *layer_set_node_bias(struct layer *layer, return bias; } +static void bias_accumulate(s8 *bias, s8 add) +{ + s32 x = *bias; + x += add; + if (x > 100) + x = 100; + if (x < -100) + x = -100; + *bias = x; +} + void layer_apply_biases(const struct layer *layer, const struct gossmap *gossmap, s8 *biases) @@ -993,8 +1004,8 @@ void layer_apply_biases(const struct layer *layer, c = gossmap_nth_chan(gossmap, n, i, &dir); idx = (gossmap_chan_idx(gossmap, c) << 1) | dir; - biases[idx] += node_bias->out_bias; - biases[idx ^ 1] += node_bias->in_bias; + bias_accumulate(&biases[idx], node_bias->out_bias); + bias_accumulate(&biases[idx ^ 1], node_bias->in_bias); } } @@ -1002,12 +1013,13 @@ void layer_apply_biases(const struct layer *layer, bias; bias = bias_hash_next(layer->biases, &it)) { struct gossmap_chan *c; + u32 idx; c = gossmap_find_chan(gossmap, &bias->scidd.scid); if (!c) continue; - biases[(gossmap_chan_idx(gossmap, c) << 1) | bias->scidd.dir] - += bias->bias; + idx = (gossmap_chan_idx(gossmap, c) << 1) | bias->scidd.dir; + bias_accumulate(&biases[idx], bias->bias); } } diff --git a/plugins/xpay/xpay.c b/plugins/xpay/xpay.c index 2267f25ccd3c..fdb35ad8a168 100644 --- a/plugins/xpay/xpay.c +++ b/plugins/xpay/xpay.c @@ -66,6 +66,18 @@ static struct gossmap *get_gossmap(struct xpay *xpay) return xpay->global_gossmap; } +/* A record of a weird error returned by a forwarding node. */ +struct weird_error { + struct short_channel_id scid; + enum onion_wire failcode; +}; + +/* A per node record of weird errors. */ +struct noderr { + struct node_id nodeid; + struct weird_error *errs; +}; + /* The unifies bolt11 and bolt12 handling */ struct payment { /* Inside xpay->payments */ @@ -143,6 +155,9 @@ struct payment { /* Useful information from prior attempts if any. */ char *prior_results; + /* Keep a record of nodes that returned weird errors. */ + struct noderr **noderrs; + /* Requests currently outstanding */ struct out_req **requests; @@ -903,6 +918,168 @@ static void payment_already_paid(struct payment *payment) send_outreq(req); } +static void append_node_error(struct noderr *noderr, + struct short_channel_id scid, + enum onion_wire failcode) +{ + struct weird_error err; + err.scid = scid; + err.failcode = failcode; + tal_arr_expand(&noderr->errs, err); +} + +static const char *fmt_onion_error(const tal_t *ctx, enum onion_wire failcode) +{ + const char *name = onion_wire_name(failcode), *str; + if (strstarts(name, "WIRE_")) + str = str_lowering(ctx, name + strlen("WIRE_")); + else + str = tal_strdup(ctx, name); + return str; +} + +/* eg. "unknown_next_peer on 1x2x3, fee_insufficient on 4x5x6" */ +static const char *fmt_noderr(const tal_t *ctx, const struct noderr *noderr) +{ + char *s = tal_strdup(ctx, ""); + + for (size_t i = 0; i < tal_count(noderr->errs); i++) { + const char *name = + fmt_onion_error(tmpctx, noderr->errs[i].failcode); + tal_append_fmt( + &s, "%s%s on %s", i == 0 ? "" : ", ", name, + fmt_short_channel_id(tmpctx, noderr->errs[i].scid)); + } + return s; +} + +/* A node failing too often with weird errors is probably going to fail every + * other request. */ +static void maybe_exclude_node(struct command *aux_cmd, struct attempt *attempt, + size_t index, enum onion_wire failcode) +{ + struct payment *payment = attempt->payment; + struct out_req *req; + struct node_id nodeid; + struct short_channel_id scid; + struct noderr *current_noderr = NULL; + bool same_channel = false; + + /* we returned the error ourselves */ + if (index == 0) + return; + + scid = attempt->hops[index].scidd.scid; + node_id_from_pubkey(&nodeid, &attempt->hops[index - 1].next_node); + + for (size_t i = 0; i < tal_count(payment->noderrs); i++) { + if (node_id_eq(&payment->noderrs[i]->nodeid, &nodeid)) { + current_noderr = payment->noderrs[i]; + + for (size_t j = 0; j < tal_count(current_noderr->errs); + j++) { + if (short_channel_id_eq( + scid, current_noderr->errs[j].scid)) { + same_channel = true; + break; + } + } + + if (!same_channel) { + /* We have not seen this scid failing for this + * node before. */ + append_node_error(current_noderr, scid, + failcode); + } + + break; + } + } + + if (!current_noderr) { + current_noderr = tal(payment, struct noderr); + current_noderr->nodeid = nodeid; + current_noderr->errs = + tal_arr(current_noderr, struct weird_error, 0); + tal_arr_expand(&payment->noderrs, current_noderr); + + append_node_error(current_noderr, scid, failcode); + } + + if (same_channel) { + /* Our fault. We already saw some weird error on this channel + * and we still try it a second time. Probably two parallel + * attempts shared the same channel. But we don't want to + * penalize this node twice for the same observation. */ + return; + } + + /* Also add a bias to this channel, so that future payments avoid it. + * It doesn't apply to fake channels because of name clash, these are + * kept private between payments. */ + if (!attempt->hops[index].fake_channel) { + add_result_summary(attempt, LOG_DBG, + "adding a global bias to channel %s", + describe_scidd(attempt, index)); + req = payment_ignored_req(aux_cmd, attempt, + "askrene-bias-channel"); + json_add_string(req->js, "layer", "xpay"); + json_add_short_channel_id_dir(req->js, "short_channel_id_dir", + attempt->hops[index].scidd); + json_add_s32(req->js, "bias", -5); /* cost x 1.18 */ + json_add_bool(req->js, "relative", true); + json_add_string( + req->js, "description", + tal_fmt(tmpctx, "xpay: weird error %s during payment %s", + fmt_onion_error(tmpctx, failcode), + fmt_sha256(tmpctx, &payment->payment_hash))); + send_payment_req(aux_cmd, attempt->payment, req); + } + + if (tal_count(current_noderr->errs) >= 2) { + /* Also add a bias to this node, so that future payments avoid + * it. */ + add_result_summary( + attempt, LOG_DBG, "adding a global bias to node %s", + fmt_node_id(tmpctx, ¤t_noderr->nodeid)); + req = + payment_ignored_req(aux_cmd, attempt, "askrene-bias-node"); + json_add_string(req->js, "layer", "xpay"); + json_add_node_id(req->js, "node", ¤t_noderr->nodeid); + json_add_string(req->js, "direction", "out"); + json_add_s32(req->js, "bias", -10); /* cost x 1.41 */ + json_add_bool(req->js, "relative", true); + json_add_string( + req->js, "description", + tal_fmt( + tmpctx, + "xpay: too many weird errors (%s) during payment %s", + fmt_noderr(tmpctx, current_noderr), + fmt_sha256(tmpctx, &payment->payment_hash))); + send_payment_req(aux_cmd, attempt->payment, req); + } + + /* Our tolerance could be any number, but the higher it is + * we risk failing the payment retrying too much on a bad node. */ + if (tal_count(current_noderr->errs) >= 2) { + /* FIXME: we should check if this node is a compulsory bridge + * between us and the destination (eg. an LSP), and in that case + * we should not disable it. A high tolerance value reduces + * this risk. */ + add_result_summary( + attempt, LOG_DBG, + "Repeated weird errors (%s) from %s: " + "disabling node for this payment", + fmt_noderr(tmpctx, current_noderr), + fmt_node_id(tmpctx, ¤t_noderr->nodeid)); + req = payment_ignored_req(aux_cmd, attempt, + "askrene-disable-node"); + json_add_string(req->js, "layer", payment->private_layer); + json_add_node_id(req->js, "node", ¤t_noderr->nodeid); + send_payment_req(aux_cmd, attempt->payment, req); + } +} + static void update_knowledge_from_error(struct command *aux_cmd, const char *buf, const jsmntok_t *error, @@ -997,11 +1174,7 @@ static void update_knowledge_from_error(struct command *aux_cmd, } else from_final = false; failcode = fromwire_peektype(replymsg); - failcode_name = onion_wire_name(failcode); - if (strstarts(failcode_name, "WIRE_")) - failcode_name = str_lowering(tmpctx, - failcode_name - + strlen("WIRE_")); + failcode_name = fmt_onion_error(tmpctx, failcode); /* For local errors, error message is informative. */ if (index == 0) { @@ -1067,7 +1240,12 @@ static void update_knowledge_from_error(struct command *aux_cmd, case WIRE_INVALID_ONION_BLINDING: /* Blame hop *leading to* final node */ index--; - goto strange_error; + add_result_summary( + attempt, LOG_UNUSUAL, + "Unexpected error (%s) from final node: disabling " + "%s for this payment", + errmsg, describe_scidd(attempt, index)); + goto disable_channel; case WIRE_INCORRECT_OR_UNKNOWN_PAYMENT_DETAILS: { struct xpay *xpay = xpay_of(attempt->payment->plugin); @@ -1118,7 +1296,15 @@ static void update_knowledge_from_error(struct command *aux_cmd, case WIRE_FINAL_INCORRECT_HTLC_AMOUNT: case WIRE_INCORRECT_OR_UNKNOWN_PAYMENT_DETAILS: case WIRE_MPP_TIMEOUT: - goto strange_error; + /* We disable the erroneous channel for this */ + add_result_summary( + attempt, LOG_UNUSUAL, + "Unexpected error (%s) from intermediate node: " + "disabling %s for this payment", + errmsg, describe_scidd(attempt, index)); + + maybe_exclude_node(aux_cmd, attempt, index, failcode); + goto disable_channel; case WIRE_TEMPORARY_CHANNEL_FAILURE: add_result_summary(attempt, LOG_DBG, @@ -1128,9 +1314,9 @@ static void update_knowledge_from_error(struct command *aux_cmd, fmt_amount_msat(tmpctx, attempt->hops[index].amount_out)); goto channel_capacity; + case WIRE_UNKNOWN_NEXT_PEER: case WIRE_PERMANENT_CHANNEL_FAILURE: case WIRE_REQUIRED_CHANNEL_FEATURE_MISSING: - case WIRE_UNKNOWN_NEXT_PEER: case WIRE_AMOUNT_BELOW_MINIMUM: case WIRE_FEE_INSUFFICIENT: case WIRE_INCORRECT_CLTV_EXPIRY: @@ -1144,6 +1330,7 @@ static void update_knowledge_from_error(struct command *aux_cmd, "We got a weird error (%s) for %s: disabling it for this payment", errmsg, describe_scidd(attempt, index)); + maybe_exclude_node(aux_cmd, attempt, index, failcode); goto disable_channel; case WIRE_INVALID_ONION_BLINDING: @@ -1157,14 +1344,6 @@ static void update_knowledge_from_error(struct command *aux_cmd, } } -strange_error: - /* We disable the erroneous channel for this */ - add_result_summary(attempt, LOG_UNUSUAL, - "Unexpected error (%s) from %s node: disabling %s for this payment", - errmsg, - from_final ? "final" : "intermediate", - describe_scidd(attempt, index)); - disable_channel: /* We only do this for the current payment */ req = payment_ignored_req(aux_cmd, attempt, "askrene-update-channel"); @@ -2584,6 +2763,7 @@ static struct payment *new_payment(const tal_t *ctx, list_head_init(&payment->past_attempts); payment->amount_being_routed = AMOUNT_MSAT(0); payment->prior_results = tal_strdup(payment, ""); + payment->noderrs = tal_arr(payment, struct noderr*, 0); payment->requests = tal_arr(payment, struct out_req *, 0); payment->start_time = clock_time(); payment->pay_compat = as_pay; diff --git a/tests/plugins/fail_unknown_next_peer.py b/tests/plugins/fail_unknown_next_peer.py new file mode 100755 index 000000000000..a8587fb5a26b --- /dev/null +++ b/tests/plugins/fail_unknown_next_peer.py @@ -0,0 +1,21 @@ +#!/usr/bin/env python3 +"""Fail payment forwards with unknown_next_peer. Leave local invoices alone. + +Used by test_xpay_unknown_next_peer_excludes_node (issue 9590). +""" +from pyln.client import Plugin + +plugin = Plugin() + + +@plugin.hook("htlc_accepted") +def on_htlc_accepted(onion, plugin, **kwargs): + # Forwards carry forward_msat. Local invoices and funding HTLCs do not. + if not isinstance(onion, dict) or onion.get("forward_msat") is None: + return {"result": "continue"} + plugin.log("failing forward with unknown_next_peer") + # WIRE_UNKNOWN_NEXT_PEER = PERM | 10 = 0x400a + return {"result": "fail", "failure_message": "400a"} + + +plugin.run() diff --git a/tests/test_xpay.py b/tests/test_xpay.py index d0e2abe63e5b..39310cee4a4d 100644 --- a/tests/test_xpay.py +++ b/tests/test_xpay.py @@ -1486,3 +1486,115 @@ def test_sendamount_bip353(node_factory): ret = l2.rpc.sendamount("fake@fake.com", "100sat") assert ret["successful_parts"] == 1 assert ret["amount_sent_msat"] == 100000 + + +def test_xpay_unknown_next_peer_excludes_node(node_factory, bitcoind): + """Issue 9590: repeated unknown_next_peer must exclude the next node. + + payer -> hub -> {a,b,c,d} -> dest + + hub fails every forward with unknown_next_peer (the code lnd returns when + the next peer is offline). A single failure may be a stale scid, so the + first channel is disabled and another path is allowed. The second failure + to the same next node must exclude that node, so xpay must not walk every + remaining channel into it. + """ + plugin = os.path.join(os.path.dirname(__file__), 'plugins/fail_unknown_next_peer.py') + payer, hub, a, b, c, d, dest = node_factory.get_nodes( + 7, opts=[{}, + {'plugin': plugin}, + {}, + {}, + {}, + {}, + {}]) + node_factory.join_nodes([payer, hub], fundamount=10**6, wait_for_announce=True) + for spoke in (a, b, c, d): + node_factory.join_nodes([hub, spoke, dest], fundamount=10**6, wait_for_announce=True) + + wait_for(lambda: len(payer.rpc.listchannels()['channels']) >= 9 * 2) + + inv = dest.rpc.invoice(10000, 'issue-9590', 'issue 9590')['bolt11'] + started = time.time() + with pytest.raises(RpcError) as err: + payer.rpc.xpay(invstring=inv, retry_for=15) + elapsed = time.time() - started + + msg = err.value.error['message'] + # One channel disable, then the node is excluded. Walking all four exits + # is the bug. The exclusion line also contains the failcode name. + unknown = msg.count('We got a weird error (unknown_next_peer)') + assert 0 < unknown <= 2, msg + assert elapsed < 10, 'spent the retry window walking the same node: {}'.format(msg) + assert 'disabling node' in msg or 'Repeated weird errors' in msg + + +def setup_failing_hub(node_factory, num_spokes, alt_ppm): + """payer -> hub -> {spokes} -> dest, plus payer -> alt -> altspoke -> dest. + + hub is the cheap, well-connected path but fails every forward with + fee_insufficient (with no channel_update, so there is nothing to learn + from it). The alternative path through alt charges alt_ppm. + """ + + def setup(plugin): + @plugin.hook("htlc_accepted") + def on_htlc_accepted(onion, plugin, **kwargs): + # Forwards carry forward_msat. Local invoices do not. + if onion.get("forward_msat") is None: + return {"result": "continue"} + # WIRE_FEE_INSUFFICIENT = UPDATE|12, htlc_msat, empty channel_update + return {"result": "fail", "failure_message": "100c" + "00" * 8 + "0000"} + + payer = node_factory.get_node() + hub = node_factory.get_node(inline_plugin=setup) + alt, altspoke, dest, *spokes = node_factory.get_nodes(3 + num_spokes) + node_factory.join_nodes([payer, hub], fundamount=10**6, wait_for_announce=True) + for spoke in spokes: + node_factory.join_nodes( + [hub, spoke, dest], fundamount=10**6, wait_for_announce=True + ) + node_factory.join_nodes( + [payer, alt, altspoke, dest], fundamount=10**6, wait_for_announce=True + ) + + alt.rpc.setchannel(altspoke.info["id"], feebase=1, feeppm=alt_ppm) + num_chans = 1 + 2 * num_spokes + 3 + wait_for(lambda: len(payer.rpc.listchannels()["channels"]) == num_chans * 2) + wait_for( + lambda: ( + [ + c["fee_per_millionth"] + for c in payer.rpc.listchannels(source=alt.info["id"])["channels"] + if c["destination"] == altspoke.info["id"] + ] + == [alt_ppm] + ) + ) + return payer, hub, alt, dest + + +def test_xpay_fee_insufficient_bias(node_factory, bitcoind): + """A hub repeatedly returning fee_insufficient gets a node bias. + + The alternative route is only slightly more expensive, so the node bias + added on the second failure is enough to route around the hub: we should + not need to disable the hub. + """ + payer, hub, alt, dest = setup_failing_hub(node_factory, num_spokes=5, alt_ppm=300) + + inv = dest.rpc.invoice(100000, "fee-bias", "fee-bias")["bolt11"] + ret = payer.rpc.xpay(invstring=inv, retry_for=30) + assert 0 < ret["failed_parts"] <= 2, ret + assert payer.daemon.is_in_log("disabling node for this payment") + assert payer.daemon.is_in_log( + "adding a global bias to node {}".format(hub.info["id"]) + ) + + # The bias persists in the xpay layer for future payments. + layer = only_one(payer.rpc.askrene_listlayers("xpay")["layers"]) + node_bias = only_one( + [b for b in layer["node_biases"] if b["node"] == hub.info["id"]] + ) + assert node_bias["out_bias"] < 0 + assert "fee_insufficient" in node_bias["description"]