From f5985171bdb40066d1c168608867b19dd85de25b Mon Sep 17 00:00:00 2001
From: Christian Decker <decker.christian@gmail.com>
Date: Mon, 10 Aug 2020 15:19:46 +0200
Subject: [PATCH] gossipd: Make gossipd much quieter

We are logging way too much from gossipd, causing noisy logs. This PR reduces
logs for incoming messages to those that actually caused a change in our
internal state (duplicate and old messages are just dropped silently now).

Changelog-Changed: gossipd: The `gossipd` is now a lot quieter, and will log only when a message changed our network topology.
---
 gossipd/routing.c | 68 ++++++++++++++++++++++-------------------------
 1 file changed, 32 insertions(+), 36 deletions(-)

diff --git a/gossipd/routing.c b/gossipd/routing.c
index 53882955d..c275a8a5a 100644
--- a/gossipd/routing.c
+++ b/gossipd/routing.c
@@ -2090,13 +2090,11 @@ bool routing_add_channel_update(struct routing_state *rstate,
 
 	/* Check timestamp is sane (unless from store). */
 	if (!index && !timestamp_reasonable(rstate, timestamp)) {
-		status_peer_debug(peer ? &peer->id : NULL,
-				  "Ignoring update timestamp %u for %s/%u",
-				  timestamp,
-				  type_to_string(tmpctx,
-						 struct short_channel_id,
-						 &short_channel_id),
-				  direction);
+		SUPERVERBOSE("Ignoring update timestamp %u for %s/%u",
+			     timestamp,
+			     type_to_string(tmpctx, struct short_channel_id,
+					    &short_channel_id),
+			     direction);
 		return false;
 	}
 
@@ -2127,14 +2125,12 @@ bool routing_add_channel_update(struct routing_state *rstate,
 		/* Allow redundant updates once every 7 days */
 		if (timestamp < hc->bcast.timestamp + GOSSIP_PRUNE_INTERVAL(rstate->dev_fast_gossip_prune) / 2
 		    && !cupdate_different(rstate->gs, hc, update)) {
-			status_peer_debug(peer ? &peer->id : NULL,
-					  "Ignoring redundant update for %s/%u"
-					  " (last %u, now %u)",
-					  type_to_string(tmpctx,
-							 struct short_channel_id,
-							 &short_channel_id),
-					  direction,
-					  hc->bcast.timestamp, timestamp);
+			SUPERVERBOSE("Ignoring redundant update for %s/%u"
+				     " (last %u, now %u)",
+				     type_to_string(tmpctx,
+						    struct short_channel_id,
+						    &short_channel_id),
+				     direction, hc->bcast.timestamp, timestamp);
 			/* Ignoring != failing */
 			return true;
 		}
@@ -2221,6 +2217,14 @@ bool routing_add_channel_update(struct routing_state *rstate,
 		process_pending_node_announcement(rstate, &chan->nodes[1]->id);
 		tal_free(uc);
 	}
+
+	status_peer_debug(peer ? &peer->id : NULL,
+			  "Received channel_update for channel %s/%d now %s",
+			  type_to_string(tmpctx, struct short_channel_id,
+					 &short_channel_id),
+			  channel_flags & 0x01,
+			  channel_flags & ROUTING_FLAGS_DISABLED ? "DISABLED" : "ACTIVE");
+
 	return true;
 }
 
@@ -2368,13 +2372,6 @@ u8 *handle_channel_update(struct routing_state *rstate, const u8 *update TAKES,
 		return err;
 	}
 
-	status_peer_debug(peer ? &peer->id : NULL,
-			  "Received channel_update for channel %s/%d now %s",
-			  type_to_string(tmpctx, struct short_channel_id,
-					 &short_channel_id),
-			  channel_flags & 0x01,
-			  channel_flags & ROUTING_FLAGS_DISABLED ? "DISABLED" : "ACTIVE");
-
 	routing_add_channel_update(rstate, take(serialized), 0, peer);
 	return NULL;
 }
@@ -2439,13 +2436,6 @@ bool routing_add_node_announcement(struct routing_state *rstate,
 		return false;
 	}
 
-	/* Only log this if *not* loading from store. */
-	if (!index)
-		status_peer_debug(peer ? &peer->id : NULL,
-				  "Received node_announcement for node %s",
-				  type_to_string(tmpctx, struct node_id,
-						 &node_id));
-
 	node = get_node(rstate, &node_id);
 
 	if (node == NULL || !node_has_broadcastable_channels(node)) {
@@ -2500,13 +2490,11 @@ bool routing_add_node_announcement(struct routing_state *rstate,
 		/* Allow redundant updates once every 7 days */
 		if (timestamp < node->bcast.timestamp + GOSSIP_PRUNE_INTERVAL(rstate->dev_fast_gossip_prune) / 2
 		    && !nannounce_different(rstate->gs, node, msg)) {
-			status_peer_debug(peer ? &peer->id : NULL,
-					  "Ignoring redundant nannounce for %s"
-					  " (last %u, now %u)",
-					  type_to_string(tmpctx,
-							 struct node_id,
-							 &node_id),
-					  node->bcast.timestamp, timestamp);
+			SUPERVERBOSE(
+			    "Ignoring redundant nannounce for %s"
+			    " (last %u, now %u)",
+			    type_to_string(tmpctx, struct node_id, &node_id),
+			    node->bcast.timestamp, timestamp);
 			/* Ignoring != failing */
 			return true;
 		}
@@ -2553,6 +2541,14 @@ bool routing_add_node_announcement(struct routing_state *rstate,
 					   NULL);
 		peer_supplied_good_gossip(peer, 1);
 	}
+
+	/* Only log this if *not* loading from store. */
+	if (!index)
+		status_peer_debug(peer ? &peer->id : NULL,
+				  "Received node_announcement for node %s",
+				  type_to_string(tmpctx, struct node_id,
+						 &node_id));
+
 	return true;
 }