plugins/pay: try without routehints first.

This is the direct cause of the failure of the original
test_pay_direct test and it makes sense: invoice routehints may not be
necessary, so try without them *first* rather than last.

We didn't mention the use of routehints in CHANGELOG at all yet, so
do that now.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

CHANGELOG.md

@@ -11,6 +11,7 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.
 
 - plugins: fully enabled, and ready for you to write some!
 - plugins: `pay` is now a plugin.
+- protocol: `pay` will now use routehints in invoices if it needs to.
 - lightning-cli: `help <cmd>` finds man pages even if `make install` not run.
 - JSON API: `waitsendpay` now has an `erring_direction` field.
 - JSON API: `listpeers` now has a `direction` field in `channels`.

plugins/pay.c

@@ -92,7 +92,10 @@ struct pay_command {
 	/* Channels which have failed us. */
 	const char **excludes;
 
-	/* Any routehints to use. */
+	/* Current routehint, if any. */
+	struct route_info *current_routehint;
+
+	/* Any remaining routehints to try. */
 	struct route_info **routehints;
 
 	/* Current node during shadow route calculation. */
@@ -179,12 +182,23 @@ static struct command_result *waitsendpay_expired(struct command *cmd,
 	return command_done_err(cmd, PAY_STOPPED_RETRYING, errmsg, data);
 }
 
-/* Try again with the next routehint (or none if that was the last) */
 static struct command_result *next_routehint(struct command *cmd,
 					     struct pay_command *pc)
 {
-	tal_arr_remove(&pc->routehints, 0);
+	if (tal_count(pc->routehints) > 0) {
-	return start_pay_attempt(cmd, pc, "Removed route hint");
+		pc->current_routehint = pc->routehints[0];
+		tal_arr_remove(&pc->routehints, 0);
+		return start_pay_attempt(cmd, pc, "Trying route hint");
+	}
+
+	/* No (more) routehints; we're out of routes. */
+	/* If we eliminated one because it was too pricy, return that. */
+	if (pc->expensive_route)
+		return command_fail(cmd, PAY_ROUTE_TOO_EXPENSIVE,
+				    "%s", pc->expensive_route);
+
+	return command_fail(cmd, PAY_ROUTE_NOT_FOUND,
+				    "Could not find a route");
 }
 
 static struct command_result *waitsendpay_error(struct command *cmd,
@@ -222,9 +236,8 @@ static struct command_result *waitsendpay_error(struct command *cmd,
 		return waitsendpay_expired(cmd, pc);
 	}
 
-	/* If failure is in routehint part, eliminate that */
+	/* If failure is in routehint part, try next one */
-	if (tal_count(pc->routehints) != 0
+	if (channel_in_routehint(pc->current_routehint, buf, scidtok))
-	    && channel_in_routehint(pc->routehints[0], buf, scidtok))
 		return next_routehint(cmd, pc);
 
 	/* Otherwise, add erring channel to exclusion list. */
@@ -370,8 +383,7 @@ static bool maybe_exclude(struct pay_command *pc,
 
 	scid = json_get_member(buf, route, "channel");
 
-	if (tal_count(pc->routehints) != 0
+	if (channel_in_routehint(pc->current_routehint, buf, scid))
-	    && channel_in_routehint(pc->routehints[0], buf, scid))
 		return false;
 
 	dir = json_get_member(buf, route, "direction");
@@ -399,9 +411,9 @@ static struct command_result *getroute_done(struct command *cmd,
 		plugin_err("getroute gave no 'route'? '%.*s'",
 			   result->end - result->start, buf);
 
-	if (tal_count(pc->routehints))
+	if (pc->current_routehint)
 		attempt->route = join_routehint(pc->ps->attempts, buf, t,
-						pc, pc->routehints[0]);
+						pc, pc->current_routehint);
 	else
 		attempt->route = json_strdup(pc->ps->attempts, buf, t);
 
@@ -441,11 +453,7 @@ static struct command_result *getroute_done(struct command *cmd,
 						 pc->excludes[tal_count(pc->excludes)-1]);
 		}
 
-		if (tal_count(pc->routehints) != 0)
+		return next_routehint(cmd, pc);
-			return next_routehint(cmd, pc);
-
-		return command_fail(cmd, PAY_ROUTE_TOO_EXPENSIVE,
-				    "%s", pc->expensive_route);
 	}
 
 	if (delay > pc->maxdelay) {
@@ -472,11 +480,7 @@ static struct command_result *getroute_done(struct command *cmd,
 						 pc->excludes[tal_count(pc->excludes)-1]);
 		}
 
-		if (tal_count(pc->routehints) != 0)
+		return next_routehint(cmd, pc);
-			return next_routehint(cmd, pc);
-
-		return command_fail(cmd, PAY_ROUTE_TOO_EXPENSIVE,
-				    "%s", pc->expensive_route);
 	}
 
 	if (pc->desc)
@@ -497,18 +501,21 @@ static struct command_result *getroute_error(struct command *cmd,
 					     const jsmntok_t *error,
 					     struct pay_command *pc)
 {
+	int code;
+	const jsmntok_t *codetok;
+
 	attempt_failed_tok(pc, "getroute", buf, error);
 
-	/* If we were trying to use a routehint, remove and try again. */
+	codetok = json_get_member(buf, error, "code");
-	if (tal_count(pc->routehints) != 0)
+	if (!json_to_int(buf, codetok, &code))
-		return next_routehint(cmd, pc);
+		plugin_err("getroute error gave no 'code'? '%.*s'",
+			   error->end - error->start, buf + error->start);
 
-	/* If we've run out of routes, there might be a good reason. */
+	/* Strange errors from getroute should be forwarded. */
-	if (pc->expensive_route)
+	if (code != PAY_ROUTE_NOT_FOUND)
-		return command_fail(cmd, PAY_ROUTE_TOO_EXPENSIVE,
+		return forward_error(cmd, buf, error, pc);
-				    "%s", pc->expensive_route);
 
-	return forward_error(cmd, buf, error, pc);
+	return next_routehint(cmd, pc);
 }
 
 /* Deep copy of excludes array. */
@@ -559,17 +566,17 @@ static struct command_result *start_pay_attempt(struct command *cmd,
 
 	/* If we have a routehint, try that first; we need to do extra
 	 * checks that it meets our criteria though. */
-	if (tal_count(pc->routehints)) {
+	if (pc->current_routehint) {
 		amount = route_msatoshi(pc->msatoshi,
-					pc->routehints[0],
+					pc->current_routehint,
-					tal_count(pc->routehints[0]));
+					tal_count(pc->current_routehint));
 		dest = type_to_string(tmpctx, struct pubkey,
-				      &pc->routehints[0][0].pubkey);
+				      &pc->current_routehint[0].pubkey);
-		max_hops -= tal_count(pc->routehints[0]);
+		max_hops -= tal_count(pc->current_routehint);
 		cltv = route_cltv(pc->final_cltv,
-				  pc->routehints[0],
+				  pc->current_routehint,
-				  tal_count(pc->routehints[0]));
+				  tal_count(pc->current_routehint));
-		attempt.routehint = tal_steal(pc->ps, pc->routehints[0]);
+		attempt.routehint = tal_steal(pc->ps, pc->current_routehint);
 	} else {
 		amount = pc->msatoshi;
 		dest = pc->dest;
@@ -871,6 +878,8 @@ static struct command_result *handle_pay(struct command *cmd,
 	pc->stoptime = timeabs_add(time_now(), time_from_sec(*retryfor));
 	pc->excludes = tal_arr(cmd, const char *, 0);
 	pc->ps = add_pay_status(pc, b11str);
+	/* We try first without using routehint */
+	pc->current_routehint = NULL;
 	pc->routehints = filter_routehints(pc, b11->routes);
 	pc->expensive_route = NULL;
 

tests/test_pay.py

@@ -76,10 +76,14 @@ def test_pay_limits(node_factory):
 
     # It should have retried (once without routehint, too)
     status = l1.rpc.call('paystatus', {'bolt11': inv['bolt11']})['pay'][0]['attempts']
-    assert len(status) == 3
+
+    # Hits weird corner case: it excludes channel, then uses routehint
+    # which reintroduces it, so then it excludes other channel.
+    assert len(status) == 4
     assert status[0]['strategy'] == "Initial attempt"
     assert status[1]['strategy'].startswith("Excluded expensive channel ")
-    assert status[2]['strategy'] == "Removed route hint"
+    assert status[2]['strategy'] == "Trying route hint"
+    assert status[3]['strategy'].startswith("Excluded expensive channel ")
 
     # Delay too high.
     with pytest.raises(RpcError, match=r'Route wanted delay of .* blocks') as err:
@@ -88,10 +92,11 @@ def test_pay_limits(node_factory):
     assert err.value.error['code'] == PAY_ROUTE_TOO_EXPENSIVE
     # Should also have retried.
     status = l1.rpc.call('paystatus', {'bolt11': inv['bolt11']})['pay'][1]['attempts']
-    assert len(status) == 3
+    assert len(status) == 4
     assert status[0]['strategy'] == "Initial attempt"
     assert status[1]['strategy'].startswith("Excluded delaying channel ")
-    assert status[2]['strategy'] == "Removed route hint"
+    assert status[2]['strategy'] == "Trying route hint"
+    assert status[3]['strategy'].startswith("Excluded delaying channel ")
 
     # This works, because fee is less than exemptfee.
     l1.rpc.call('pay', {'bolt11': inv['bolt11'], 'msatoshi': 100000, 'maxfeepercent': 0.0001, 'exemptfee': 2000})
@@ -1259,13 +1264,21 @@ def test_pay_routeboost(node_factory, bitcoind):
     assert 'description' not in only_one(status['pay'])
     assert 'routehint_modifications' not in only_one(status['pay'])
     assert 'local_exclusions' not in only_one(status['pay'])
-    attempt = only_one(only_one(status['pay'])['attempts'])
+    # First attempt will fail, then it will try route hint
-    assert attempt['age_in_seconds'] <= time.time() - start
+    attempts = only_one(status['pay'])['attempts']
-    assert attempt['duration_in_seconds'] <= end - start
+    assert len(attempts) == 2
-    assert only_one(attempt['routehint'])
+    assert attempts[0]['strategy'] == "Initial attempt"
-    assert only_one(attempt['routehint'])['id'] == l3.info['id']
+    # FIXME!
-    assert only_one(attempt['routehint'])['msatoshi'] == 10**5 + 1 + 10**5 // 100000
+    PAY_ROUTE_NOT_FOUND = 205
-    assert only_one(attempt['routehint'])['delay'] == 5 + 6
+    assert attempts[0]['failure']['code'] == PAY_ROUTE_NOT_FOUND
+    assert attempts[1]['strategy'] == "Trying route hint"
+    assert 'success' in attempts[1]
+    assert attempts[1]['age_in_seconds'] <= time.time() - start
+    assert attempts[1]['duration_in_seconds'] <= end - start
+    assert only_one(attempts[1]['routehint'])
+    assert only_one(attempts[1]['routehint'])['id'] == l3.info['id']
+    assert only_one(attempts[1]['routehint'])['msatoshi'] == 10**5 + 1 + 10**5 // 100000
+    assert only_one(attempts[1]['routehint'])['delay'] == 5 + 6
 
     # With dev-route option we can test longer routehints.
     if DEVELOPER:
@@ -1287,43 +1300,11 @@ def test_pay_routeboost(node_factory, bitcoind):
                                       'dev-routes': [routel3l4l5]})
         l1.rpc.pay(inv['bolt11'])
         status = l1.rpc.call('paystatus', [inv['bolt11']])
-        assert len(only_one(status['pay'])['attempts']) == 1
-        assert 'failure' not in only_one(status['pay'])['attempts'][0]
-        assert 'success' in only_one(status['pay'])['attempts'][0]
-
-        # Now test that it falls back correctly to not using routeboost
-        # if it can't route to the node mentioned
-        routel4l3 = [{'id': l4.info['id'],
-                      'short_channel_id': scid34,
-                      'fee_base_msat': 1000,
-                      'fee_proportional_millionths': 10,
-                      'cltv_expiry_delta': 6}]
-        inv = l3.rpc.call('invoice', {'msatoshi': 10**5,
-                                      'label': 'test_pay_routeboost3',
-                                      'description': 'test_pay_routeboost3',
-                                      'dev-routes': [routel4l3]})
-        l1.rpc.pay(inv['bolt11'])
-        status = l1.rpc.call('paystatus', [inv['bolt11']])
         assert len(only_one(status['pay'])['attempts']) == 2
         assert 'failure' in only_one(status['pay'])['attempts'][0]
         assert 'success' not in only_one(status['pay'])['attempts'][0]
-        routehint = only_one(status['pay'])['attempts'][0]['routehint']
-        assert [h['channel'] for h in routehint] == [r['short_channel_id'] for r in routel4l3]
         assert 'failure' not in only_one(status['pay'])['attempts'][1]
         assert 'success' in only_one(status['pay'])['attempts'][1]
-        assert 'routehint' not in only_one(status['pay'])['attempts'][1]
-
-        # Similarly if it can route, but payment fails.
-        routel2bad = [{'id': l2.info['id'],
-                       'short_channel_id': scid34,  # Invalid scid
-                       'fee_base_msat': 1000,
-                       'fee_proportional_millionths': 10,
-                       'cltv_expiry_delta': 6}]
-        inv = l3.rpc.call('invoice', {'msatoshi': 10**5,
-                                      'label': 'test_pay_routeboost4',
-                                      'description': 'test_pay_routeboost4',
-                                      'dev-routes': [routel2bad]})
-        l1.rpc.pay(inv['bolt11'])
 
         # Finally, it should fall back to second routehint if first fails.
         # (Note, this is not public because it's not 6 deep)
@@ -1350,13 +1331,14 @@ def test_pay_routeboost(node_factory, bitcoind):
         assert 'local_exclusions' not in only_one(status['pay'])
         attempts = only_one(status['pay'])['attempts']
 
-        # First failed, second succeeded.
+        # First two failed (w/o routehint and w bad hint), third succeeded.
-        assert len(attempts) == 2
+        assert len(attempts) == 3
         assert 'success' not in attempts[0]
-        assert 'success' in attempts[1]
+        assert 'success' not in attempts[1]
+        assert 'success' in attempts[2]
 
-        assert [h['channel'] for h in attempts[0]['routehint']] == [r['short_channel_id'] for r in routel3l4l5]
+        assert [h['channel'] for h in attempts[1]['routehint']] == [r['short_channel_id'] for r in routel3l4l5]
-        assert [h['channel'] for h in attempts[1]['routehint']] == [r['short_channel_id'] for r in routel3l5]
+        assert [h['channel'] for h in attempts[2]['routehint']] == [r['short_channel_id'] for r in routel3l5]
 
 
 @pytest.mark.xfail(strict=True)