gossipd: specify origin of updates in errors.

@cdecker points out that in test_forward, where we manually create a route,
we get an error back which contains an update for an unknown channel.

We should still note this, but it's not an error for testing.

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

gossipd/gossip.c

@@ -630,7 +630,8 @@ static void send_node_announcement(struct daemon *daemon)
  * details of the failures. The caller is expected to return the error to the
  * peer, or drop the error if the message did not come from a peer.
  */
-static u8 *handle_gossip_msg(struct daemon *daemon, const u8 *msg)
+static u8 *handle_gossip_msg(struct daemon *daemon, const u8 *msg,
+			     const char *source)
 {
 	struct routing_state *rstate = daemon->rstate;
 	int t = fromwire_peektype(msg);
@@ -657,7 +658,7 @@ static u8 *handle_gossip_msg(struct daemon *daemon, const u8 *msg)
 		break;
 
 	case WIRE_CHANNEL_UPDATE:
-		err = handle_channel_update(rstate, msg);
+		err = handle_channel_update(rstate, msg, source);
 		if (err)
 			return err;
 		break;
@@ -760,7 +761,7 @@ static struct io_plan *peer_msgin(struct io_conn *conn,
 	case WIRE_CHANNEL_ANNOUNCEMENT:
 	case WIRE_NODE_ANNOUNCEMENT:
 	case WIRE_CHANNEL_UPDATE:
-		err = handle_gossip_msg(peer->daemon, msg);
+		err = handle_gossip_msg(peer->daemon, msg, "peer");
 		if (err)
 			queue_peer_msg(peer, take(err));
 		return peer_next_in(conn, peer);
@@ -939,7 +940,7 @@ static struct io_plan *owner_msg_in(struct io_conn *conn,
 	int type = fromwire_peektype(msg);
 	if (type == WIRE_CHANNEL_ANNOUNCEMENT || type == WIRE_CHANNEL_UPDATE ||
 	    type == WIRE_NODE_ANNOUNCEMENT) {
-		err = handle_gossip_msg(peer->daemon, dc->msg_in);
+		err = handle_gossip_msg(peer->daemon, dc->msg_in, "subdaemon");
 		if (err)
 			queue_peer_msg(peer, take(err));
 
@@ -1482,7 +1483,7 @@ static void gossip_send_keepalive_update(struct routing_state *rstate,
 	status_trace("Sending keepalive channel_update for %s",
 		     type_to_string(tmpctx, struct short_channel_id, &scid));
 
-	err = handle_channel_update(rstate, update);
+	err = handle_channel_update(rstate, update, "keepalive");
 	if (err)
 		status_failed(STATUS_FAIL_INTERNAL_ERROR,
 			      "rejected keepalive channel_update: %s",
@@ -2420,7 +2421,7 @@ static struct io_plan *handle_disable_channel(struct io_conn *conn,
 			      strerror(errno));
 	}
 
-	err = handle_channel_update(daemon->rstate, msg);
+	err = handle_channel_update(daemon->rstate, msg, "disable_channel");
 	if (err)
 		status_failed(STATUS_FAIL_INTERNAL_ERROR,
 			      "rejected disabling channel_update: %s",

gossipd/routing.c

@@ -201,10 +201,11 @@ static void init_half_chan(struct routing_state *rstate,
 	c->last_timestamp = time_now().ts.tv_sec - rstate->prune_timeout/2;
 }
 
-static void bad_gossip_order(const u8 *msg, const char *details)
+static void bad_gossip_order(const u8 *msg, const char *source,
+			     const char *details)
 {
-	status_trace("Bad gossip order: %s before announcement %s",
-		     wire_type_name(fromwire_peektype(msg)),
+	status_trace("Bad gossip order from %s: %s before announcement %s",
+		     source, wire_type_name(fromwire_peektype(msg)),
 		     details);
 }
 
@@ -791,7 +792,7 @@ static void process_pending_channel_update(struct routing_state *rstate,
 		return;
 
 	/* FIXME: We don't remember who sent us updates, so can't error them */
-	err = handle_channel_update(rstate, cupdate);
+	err = handle_channel_update(rstate, cupdate, "pending update");
 	if (err) {
 		status_trace("Pending channel_update for %s: %s",
 			     type_to_string(tmpctx, struct short_channel_id, scid),
@@ -965,7 +966,8 @@ bool routing_add_channel_update(struct routing_state *rstate,
 	return true;
 }
 
-u8 *handle_channel_update(struct routing_state *rstate, const u8 *update)
+u8 *handle_channel_update(struct routing_state *rstate, const u8 *update,
+			  const char *source)
 {
 	u8 *serialized;
 	struct half_chan *c;
@@ -1023,6 +1025,7 @@ u8 *handle_channel_update(struct routing_state *rstate, const u8 *update)
 
 		if (!chan) {
 			bad_gossip_order(serialized,
+					 source,
 					 tal_fmt(tmpctx, "%s(%u)",
 						 type_to_string(tmpctx,
 							struct short_channel_id,
@@ -1255,7 +1258,7 @@ u8 *handle_node_announcement(struct routing_state *rstate, const u8 *node_ann)
 		pna = pending_node_map_get(rstate->pending_node_map,
 					   &node_id.pubkey);
 		if (!pna) {
-			bad_gossip_order(serialized,
+			bad_gossip_order(serialized, "node_announcement",
 					 type_to_string(tmpctx, struct pubkey,
 							&node_id));
 		} else if (pna->timestamp < timestamp) {
@@ -1437,7 +1440,7 @@ void routing_failure(struct routing_state *rstate,
 				       (int) failcode);
 			return;
 		}
-		err = handle_channel_update(rstate, channel_update);
+		err = handle_channel_update(rstate, channel_update, "error");
 		if (err) {
 			status_unusual("routing_failure: "
 				       "bad channel_update %s",

gossipd/routing.h

@@ -228,7 +228,8 @@ bool handle_pending_cannouncement(struct routing_state *rstate,
 				  const u8 *txscript);
 
 /* Returns NULL if all OK, otherwise an error for the peer which sent. */
-u8 *handle_channel_update(struct routing_state *rstate, const u8 *update);
+u8 *handle_channel_update(struct routing_state *rstate, const u8 *update,
+			  const char *source);
 
 /* Returns NULL if all OK, otherwise an error for the peer which sent. */
 u8 *handle_node_announcement(struct routing_state *rstate, const u8 *node);

tests/fixtures.py

@@ -152,7 +152,7 @@ def checkReconnect(node):
 
 
 def checkBadGossipOrder(node):
-    if node.daemon.is_in_log('Bad gossip order') and not node.daemon.is_in_log('Deleting channel'):
+    if node.daemon.is_in_log('Bad gossip order from (?!error)') and not node.daemon.is_in_log('Deleting channel'):
         return 1
     return 0
 

tests/test_lightningd.py

@@ -301,8 +301,8 @@ class BaseLightningDTests(unittest.TestCase):
 
     def checkBadGossipOrder(self, node):
         # We can have a race where we notice a channel deleted and someone
-        # sends an update.
-        if node.daemon.is_in_log('Bad gossip order') and not node.daemon.is_in_log('Deleting channel'):
+        # sends an update, and we can get unknown channel updates in errors.
+        if node.daemon.is_in_log('Bad gossip order from (?!error)') and not node.daemon.is_in_log('Deleting channel'):
             return 1
         return 0