Skip to content

Commit

Permalink
plugins/renepay: neaten the command notifications.
Browse files Browse the repository at this point in the history 
It now looks like (for test_hardmpp):

```
# we have computed a set of 1 flows with probability 0.328, fees 0msat and delay 23
#   Flow 1: amount=1800000000msat prob=0.328 fees=0msat delay=12 path=-103x2x0/1(min=max=4294967295msat)->-103x5x0/0->-103x3x0/1->
#   Flow 1: Failed at node #1 (WIRE_TEMPORARY_CHANNEL_FAILURE): failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
#   Flow 1: Failure of 1800000000msat for 103x5x0/0 capacity [0msat,3000000000msat] -> [0msat,1799999999msat]
# we have computed a set of 2 flows with probability 0.115, fees 0msat and delay 23
#   Flow 2: amount=500000000msat prob=0.475 fees=0msat delay=12 path=-103x6x0/0(min=max=4294967295msat)->-103x1x0/1->-103x4x0/1->
#   Flow 3: amount=1300000000msat prob=0.242 fees=0msat delay=12 path=-103x2x0/1(min=max=4294967295msat)->-103x5x0/0(max=1799999999msat)->-103x3x0/1->
#   Flow 3: Failed at node #1 (WIRE_TEMPORARY_CHANNEL_FAILURE): failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
#   Flow 3: Failure of 1300000000msat for 103x5x0/0 capacity [0msat,1799999999msat] -> [0msat,1299999999msat]
# we have computed a set of 2 flows with probability 0.084, fees 0msat and delay 23
#   Flow 4: amount=260000000msat prob=0.467 fees=0msat delay=12 path=-103x6x0/0(500000000msat in 1 htlcs,min=max=4294967295msat)->-103x1x0/1(500000000msat in 1 htlcs)->-103x4x0/1(500000000msat in 1 htlcs)->
#   Flow 5: amount=1040000000msat prob=0.179 fees=0msat delay=12 path=-103x2x0/1(min=max=4294967295msat)->-103x5x0/0(max=1299999999msat)->-103x3x0/1->
#   Flow 5: Failed at node #1 (WIRE_TEMPORARY_CHANNEL_FAILURE): failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
#   Flow 5: Failure of 1040000000msat for 103x5x0/0 capacity [0msat,1299999999msat] -> [0msat,1039999999msat]
# we have computed a set of 2 flows with probability 0.052, fees 0msat and delay 23
#   Flow 6: amount=120000000msat prob=0.494 fees=0msat delay=12 path=-103x6x0/0(760000000msat in 2 htlcs,min=max=4294967295msat)->-103x1x0/1(760000000msat in 2 htlcs)->-103x4x0/1(760000000msat in 2 htlcs)->
#   Flow 7: amount=920000000msat prob=0.105 fees=0msat delay=12 path=-103x2x0/1(min=max=4294967295msat)->-103x5x0/0(max=1039999999msat)->-103x3x0/1->
#   Flow 7: Success
```

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
  • Loading branch information
@rustyrussell
rustyrussell committed Aug 23, 2023
1 parent 7db6aaa commit 00e9af5
Show file tree
Hide file tree
Showing 6 changed files with 155 additions and 76 deletions.
121 changes: 87 additions & 34 deletions plugins/renepay/flow.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,52 @@ const char *fmt_chan_extra_map(
return buff;
}

const char *fmt_chan_extra_details(const tal_t *ctx,
struct chan_extra_map* chan_extra_map,
const struct short_channel_id_dir *scidd)
{
const struct chan_extra *ce = chan_extra_map_get(chan_extra_map,
scidd->scid);
const struct chan_extra_half *ch;
char *str = tal_strdup(ctx, "");
char sep = '(';

if (!ce)
return str;

ch = &ce->half[scidd->dir];
if (ch->num_htlcs != 0) {
tal_append_fmt(&str, "%c%s in %zu htlcs",
sep,
fmt_amount_msat(tmpctx, ch->htlc_total),
ch->num_htlcs);
sep = ',';
}
/* Happens with local channels, where we're certain. */
if (amount_msat_eq(ch->known_min, ch->known_max)) {
tal_append_fmt(&str, "%cmin=max=%s",
sep,
fmt_amount_msat(tmpctx, ch->known_min));
sep = ',';
} else {
if (amount_msat_greater(ch->known_min, AMOUNT_MSAT(0))) {
tal_append_fmt(&str, "%cmin=%s",
sep,
fmt_amount_msat(tmpctx, ch->known_min));
sep = ',';
}
if (!amount_msat_eq(ch->known_max, ce->capacity)) {
tal_append_fmt(&str, "%cmax=%s",
sep,
fmt_amount_msat(tmpctx, ch->known_max));
sep = ',';
}
}
if (!streq(str, ""))
tal_append_fmt(&str, ")");
return str;
}

struct chan_extra *new_chan_extra(
struct chan_extra_map *chan_extra_map,
const struct short_channel_id scid,
Expand Down Expand Up @@ -145,12 +191,12 @@ void chan_extra_can_send(

/* Update the knowledge that this (channel,direction) cannot send.*/
void chan_extra_cannot_send(
struct payment *p,
struct pay_flow *pf,
struct chan_extra_map *chan_extra_map,
const struct short_channel_id_dir *scidd,
struct amount_msat sent)
{
struct amount_msat x;
struct amount_msat oldmin, oldmax, x;
struct chan_extra *ce = chan_extra_map_get(chan_extra_map,
scidd->scid);
if(!ce)
Expand All @@ -170,20 +216,23 @@ void chan_extra_cannot_send(
x = AMOUNT_MSAT(0);
}

oldmin = ce->half[scidd->dir].known_min;
oldmax = ce->half[scidd->dir].known_max;

/* If we "knew" the capacity was at least this, we just showed we're wrong! */
if (amount_msat_less(x, ce->half[scidd->dir].known_min)) {
debug_paynote(p, "Expected scid=%s min %s, but %s failed! Setting min to 0",
type_to_string(tmpctx,struct short_channel_id_dir,scidd),
type_to_string(tmpctx,struct amount_msat,&ce->half[scidd->dir].known_min),
type_to_string(tmpctx,struct amount_msat,&x));
if (amount_msat_less(x, ce->half[scidd->dir].known_min))
ce->half[scidd->dir].known_min = AMOUNT_MSAT(0);
}

ce->half[scidd->dir].known_max = amount_msat_min(ce->half[scidd->dir].known_max,x);

debug_paynote(p,"Update chan knowledge scid=%s: [%s,%s]",
type_to_string(tmpctx,struct short_channel_id_dir,scidd),
type_to_string(tmpctx,struct amount_msat,&ce->half[scidd->dir].known_min),
type_to_string(tmpctx,struct amount_msat,&ce->half[scidd->dir].known_max));
payflow_note(pf, LOG_INFORM,
"Failure of %s for %s capacity [%s,%s] -> [%s,%s]",
fmt_amount_msat(tmpctx, sent),
type_to_string(tmpctx,struct short_channel_id_dir,scidd),
fmt_amount_msat(tmpctx, oldmin),
fmt_amount_msat(tmpctx, oldmax),
fmt_amount_msat(tmpctx, ce->half[scidd->dir].known_min),
fmt_amount_msat(tmpctx, ce->half[scidd->dir].known_max));

chan_extra_adjust_half(ce,!scidd->dir);
}
Expand Down Expand Up @@ -223,11 +272,20 @@ void chan_extra_set_liquidity(
chan_extra_set_liquidity_(ce,scidd->dir,x);
}
/* Update the knowledge that this (channel,direction) has sent x msat.*/
static void chan_extra_sent_success_(
struct chan_extra *ce,
int dir,
void chan_extra_sent_success(
struct pay_flow *pf,
struct chan_extra_map *chan_extra_map,
const struct short_channel_id_dir *scidd,
struct amount_msat x)
{
struct chan_extra *ce = chan_extra_map_get(chan_extra_map,
scidd->scid);
if(!ce)
{
debug_err("%s unexpected chan_extra ce is NULL",
__PRETTY_FUNCTION__);
}

if(amount_msat_greater(x,ce->capacity))
{
debug_err("%s unexpected capacity=%s is less than x=%s",
Expand All @@ -240,29 +298,24 @@ static void chan_extra_sent_success_(

struct amount_msat new_a, new_b;

if(!amount_msat_sub(&new_a,ce->half[dir].known_min,x))
if(!amount_msat_sub(&new_a,ce->half[scidd->dir].known_min,x))
new_a = AMOUNT_MSAT(0);
if(!amount_msat_sub(&new_b,ce->half[dir].known_max,x))
if(!amount_msat_sub(&new_b,ce->half[scidd->dir].known_max,x))
new_b = AMOUNT_MSAT(0);

ce->half[dir].known_min = new_a;
ce->half[dir].known_max = new_b;
payflow_note(pf, LOG_DBG,
"Success of %s for %s capacity [%s,%s] -> [%s,%s]",
fmt_amount_msat(tmpctx, x),
type_to_string(tmpctx,struct short_channel_id_dir,scidd),
fmt_amount_msat(tmpctx, ce->half[scidd->dir].known_min),
fmt_amount_msat(tmpctx, ce->half[scidd->dir].known_max),
fmt_amount_msat(tmpctx, new_a),
fmt_amount_msat(tmpctx, new_b));

chan_extra_adjust_half(ce,!dir);
}
void chan_extra_sent_success(
struct chan_extra_map *chan_extra_map,
const struct short_channel_id_dir *scidd,
struct amount_msat x)
{
struct chan_extra *ce = chan_extra_map_get(chan_extra_map,
scidd->scid);
if(!ce)
{
debug_err("%s unexpected chan_extra ce is NULL",
__PRETTY_FUNCTION__);
}
chan_extra_sent_success_(ce,scidd->dir,x);
ce->half[scidd->dir].known_min = new_a;
ce->half[scidd->dir].known_max = new_b;

chan_extra_adjust_half(ce,!scidd->dir);
}
/* Forget a bit about this (channel,direction) state. */
static void chan_extra_relax_(
Expand Down
11 changes: 9 additions & 2 deletions plugins/renepay/flow.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -118,6 +118,12 @@ const char *fmt_chan_extra_map(
const tal_t *ctx,
struct chan_extra_map* chan_extra_map);

/* Returns "" if nothing useful known about channel, otherwise
* "(details)" */
const char *fmt_chan_extra_details(const tal_t *ctx,
struct chan_extra_map* chan_extra_map,
const struct short_channel_id_dir *scidd);

/* Creates a new chan_extra and adds it to the chan_extra_map. */
struct chan_extra *new_chan_extra(
struct chan_extra_map *chan_extra_map,
Expand Down Expand Up @@ -152,7 +158,7 @@ void chan_extra_can_send(struct chan_extra_map *chan_extra_map,
struct amount_msat x);

/* Update the knowledge that this (channel,direction) cannot send x msat.*/
void chan_extra_cannot_send(struct payment* p,
void chan_extra_cannot_send(struct pay_flow* pf,
struct chan_extra_map *chan_extra_map,
const struct short_channel_id_dir *scidd,
struct amount_msat x);
Expand All @@ -163,7 +169,8 @@ void chan_extra_set_liquidity(struct chan_extra_map *chan_extra_map,
struct amount_msat x);

/* Update the knowledge that this (channel,direction) has sent x msat.*/
void chan_extra_sent_success(struct chan_extra_map *chan_extra_map,
void chan_extra_sent_success(struct pay_flow *pf,
struct chan_extra_map *chan_extra_map,
const struct short_channel_id_dir *scidd,
struct amount_msat x);

Expand Down
58 changes: 19 additions & 39 deletions plugins/renepay/pay.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -121,12 +121,8 @@ static struct pf_result *handle_unhandleable_error(struct pay_flow *pf,
size_t n = tal_count(pf);

/* We got a mangled reply. We don't know who to penalize! */
debug_paynote(pf->payment, "%s on route %s", what, flow_path_to_str(tmpctx, pf));

// TODO(eduardo): does LOG_BROKEN finish the plugin execution?
plugin_log(pay_plugin->plugin, LOG_BROKEN,
"%s on route %s",
what, flow_path_to_str(tmpctx, pf));
payflow_note(pf, LOG_UNUSUAL, "%s on route %s",
what, flow_path_to_str(tmpctx, pf));

if (n == 1)
{
Expand All @@ -145,9 +141,9 @@ static struct pf_result *handle_unhandleable_error(struct pay_flow *pf,
n = pseudorand(n-1);

tal_arr_expand(&pf->payment->disabled, pf->path_scidds[n].scid);
debug_paynote(pf->payment, "... eliminated %s",
type_to_string(tmpctx, struct short_channel_id,
&pf->path_scidds[n].scid));
payflow_note(pf, LOG_DBG, "... eliminated %s",
type_to_string(tmpctx, struct short_channel_id,
&pf->path_scidds[n].scid));

return pay_flow_failed(pf);
}
Expand Down Expand Up @@ -182,9 +178,10 @@ static struct command_result *addgossip_failure(struct command *cmd,
struct payment * payment = adg->pf->payment;
plugin_log(pay_plugin->plugin,LOG_DBG,"calling %s",__PRETTY_FUNCTION__);

debug_paynote(payment, "addgossip failed, removing channel %s (%.*s)",
type_to_string(tmpctx, struct short_channel_id, &adg->scid),
err->end - err->start, buf + err->start);
payflow_note(adg->pf, LOG_UNUSUAL,
"addgossip failed, removing channel %s (%.*s)",
type_to_string(tmpctx, struct short_channel_id, &adg->scid),
err->end - err->start, buf + err->start);
tal_arr_expand(&payment->disabled, adg->scid);

return addgossip_done(cmd, buf, err, adg);
Expand All @@ -195,7 +192,6 @@ static struct pf_result *submit_update(struct pay_flow *pf,
struct short_channel_id errscid)
{
plugin_log(pay_plugin->plugin,LOG_DBG,"calling %s",__PRETTY_FUNCTION__);
struct payment *payment = pf->payment;
struct out_req *req;
struct addgossip *adg = tal(pf, struct addgossip);

Expand All @@ -204,8 +200,7 @@ static struct pf_result *submit_update(struct pay_flow *pf,
adg->scid = errscid;
adg->pf = pf;

debug_paynote(payment, "... extracted channel_update, telling gossipd");
plugin_log(pay_plugin->plugin, LOG_DBG, "(update = %s)", tal_hex(tmpctx, update));
payflow_note(pf, LOG_DBG, "... extracted channel_update %s, telling gossipd", tal_hex(tmpctx, update));

req = jsonrpc_request_start(pay_plugin->plugin, NULL, "addgossip",
addgossip_done,
Expand Down Expand Up @@ -312,8 +307,8 @@ static struct command_result *flow_sendpay_failed(struct command *cmd,
plugin_err(cmd->plugin, "Strange error from sendpay: %.*s",
json_tok_full_len(err), json_tok_full(buf, err));

debug_paynote(payment,
"sendpay didn't like first hop, eliminated: %s", msg)
payflow_note(pf, LOG_INFORM,
"sendpay didn't like first hop, eliminated: %s", msg);

/* There is no new knowledge from this kind of failure.
* We just disable this scid. */
Expand All @@ -329,15 +324,11 @@ static void sendpay_new_flows(struct payment *p)
struct pay_flow *pf;

list_for_each(&p->flows, pf, list) {
struct out_req *req;

if (pf->state != PAY_FLOW_NOT_STARTED)
continue;

debug_paynote(p, "sendpay flow groupid=%"PRIu64", partid=%"PRIu64", delivering=%s, probability=%.3lf",
pf->key.groupid,
pf->key.partid,
fmt_amount_msat(tmpctx, payflow_delivered(pf)),
pf->success_prob);
struct out_req *req;
/* FIXME: We don't actually want cmd to own this sendpay, so we use NULL here,
* but we should use a variant which allows us to set json id! */
req = jsonrpc_request_start(pay_plugin->plugin, NULL, "sendpay",
Expand Down Expand Up @@ -1163,18 +1154,6 @@ static void handle_sendpay_failure_flow(struct pay_flow *pf,
{
debug_assert(pf);

struct payment * const p = pf->payment;

plugin_log(pay_plugin->plugin, LOG_UNUSUAL,
"onion error %s from node #%u %s: "
"%s",
onion_wire_name(onionerr),
erridx,
erridx == tal_count(pf->path_scidds)
? "final"
: type_to_string(tmpctx, struct short_channel_id_dir, &pf->path_scidds[erridx]),
msg);

/* we know that all channels before erridx where able to commit to this payment */
uncertainty_network_channel_can_send(
pay_plugin->chan_extra_map,
Expand All @@ -1185,10 +1164,7 @@ static void handle_sendpay_failure_flow(struct pay_flow *pf,
if((enum onion_wire)onionerr == WIRE_TEMPORARY_CHANNEL_FAILURE
&& erridx < tal_count(pf->path_scidds))
{
plugin_log(pay_plugin->plugin,LOG_DBG,
"sendpay_failure says insufficient funds!");

chan_extra_cannot_send(p,pay_plugin->chan_extra_map,
chan_extra_cannot_send(pf,pay_plugin->chan_extra_map,
&pf->path_scidds[erridx],
pf->amounts[erridx]);
}
Expand Down Expand Up @@ -1244,6 +1220,8 @@ static struct command_result *notification_sendpay_success(
json_tok_full(buf, params));
}

payflow_note(pf, LOG_INFORM, "Success");

// 2. update information
uncertainty_network_flow_success(pay_plugin->chan_extra_map, pf);

Expand Down Expand Up @@ -1302,6 +1280,8 @@ static struct pf_result *sendpay_failure(struct pay_flow *pf,
flow_path_to_str(tmpctx, pf));
}

payflow_note(pf, LOG_INFORM, "Failed at node #%u (%s): %s",
erridx, onion_wire_name(onionerr), msg);
handle_sendpay_failure_flow(pf, msg, erridx, onionerr);

return handle_sendpay_failure_payment(pf, msg, erridx, onionerr, raw);
Expand Down
36 changes: 36 additions & 0 deletions plugins/renepay/pay_flow.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -264,6 +264,23 @@ static void destroy_payment_flow(struct pay_flow *pf)
list_del_from(&pf->payment->flows, &pf->list);
}

/* Print out flow, and any information we already know */
static const char *flow_path_annotated(const tal_t *ctx,
const struct pay_flow *flow)
{
char *s = tal_strdup(ctx, "");
for (size_t i = 0; i < tal_count(flow->path_scidds); i++) {
tal_append_fmt(&s, "-%s%s->",
type_to_string(tmpctx,
struct short_channel_id_dir,
&flow->path_scidds[i]),
fmt_chan_extra_details(tmpctx,
pay_plugin->chan_extra_map,
&flow->path_scidds[i]));
}
return s;
}

/* Calculates delays and converts to scids, and links to the payment.
* Frees flows. */
static void convert_and_attach_flows(struct payment *payment,
Expand Down Expand Up @@ -310,6 +327,15 @@ static void convert_and_attach_flows(struct payment *payment,
/* Payment keeps a list of its flows. */
list_add(&payment->flows, &pf->list);

/* First time they see this: annotate important points */
payflow_note(pf, LOG_INFORM,
"amount=%s prob=%.3lf fees=%s delay=%u path=%s",
fmt_amount_msat(tmpctx, payflow_delivered(pf)),
pf->success_prob,
fmt_amount_msat(tmpctx, payflow_fee(pf)),
pf->cltv_delays[0] - pf->cltv_delays[plen-1],
flow_path_annotated(tmpctx, pf));

/* Increase totals for payment */
amount_msat_accumulate(&payment->total_sent, pf->amounts[0]);
amount_msat_accumulate(&payment->total_delivering,
Expand Down Expand Up @@ -551,6 +577,16 @@ struct amount_msat payflow_delivered(const struct pay_flow *flow)
return flow->amounts[tal_count(flow->amounts)-1];
}

/* How much does this flow pay in fees? */
struct amount_msat payflow_fee(const struct pay_flow *pf)
{
struct amount_msat fee;

if (!amount_msat_sub(&fee, pf->amounts[0], payflow_delivered(pf)))
abort();
return fee;
}

static struct pf_result *pf_resolve(struct pay_flow *pf,
enum pay_flow_state oldstate,
enum pay_flow_state newstate,
Expand Down
Loading

0 comments on commit 00e9af5

Please sign in to comment.