Reduce excess debug logging, simplify logging implementation

common/gossmap.c

@@ -503,16 +503,14 @@ static struct gossmap_chan *add_channel(struct gossmap *map,
 	return chan;
 }
 
-/* Does not set hc->nodeidx! */
-static void fill_from_update(struct gossmap *map,
+/* Does not set hc->nodeidx!
+ * Returns false if it doesn't fit in our representation: this happens
+ * on the real network, as people set absurd fees
+ */
+static bool fill_from_update(struct gossmap *map,
 			     struct short_channel_id_dir *scidd,
 			     struct half_chan *hc,
-			     u64 cupdate_off,
-			     void (*logcb)(void *cbarg,
-					   enum log_level level,
-					   const char *fmt,
-					   ...),
-			     void *cbarg)
+			     u64 cupdate_off)
 {
 	/* Note that first two bytes are message type */
 	const u64 scid_off = cupdate_off + 2 + (64 + 32);
@@ -543,18 +541,15 @@ static void fill_from_update(struct gossmap *map,
 	hc->proportional_fee = proportional_fee;
 	hc->delay = delay;
 
-	/* Check they fit: we turn off if not, log (at debug, it happens!). */
+	/* Check they fit: we turn off if not. */
 	if (hc->base_fee != base_fee
 	    || hc->proportional_fee != proportional_fee
 	    || hc->delay != delay) {
 		hc->htlc_max = 0;
 		hc->enabled = false;
-		if (logcb)
-			logcb(cbarg, LOG_DBG,
-			      "Bad cupdate for %s, ignoring (delta=%u, fee=%u/%u)",
-			      fmt_short_channel_id_dir(tmpctx, scidd),
-			      delay, base_fee, proportional_fee);
+		return false;
 	}
+	return true;
 }
 
 /* BOLT #7:
@@ -572,23 +567,24 @@ static void fill_from_update(struct gossmap *map,
  *     * [`u32`:`fee_proportional_millionths`]
  *     * [`u64`:`htlc_maximum_msat`]
  */
-static void update_channel(struct gossmap *map, u64 cupdate_off)
+static bool update_channel(struct gossmap *map, u64 cupdate_off)
 {
 	struct short_channel_id_dir scidd;
 	struct gossmap_chan *chan;
 	struct half_chan hc;
+	bool ret;
 
-	fill_from_update(map, &scidd, &hc, cupdate_off,
-			 map->logcb, map->cbarg);
+	ret = fill_from_update(map, &scidd, &hc, cupdate_off);
 	chan = gossmap_find_chan(map, &scidd.scid);
 	/* This can happen if channel gets deleted! */
 	if (!chan)
-		return;
+		return ret;
 
 	/* Preserve this */
 	hc.nodeidx = chan->half[scidd.dir].nodeidx;
 	chan->half[scidd.dir] = hc;
 	chan->cupdate_off[scidd.dir] = cupdate_off;
+	return ret;
 }
 
 static void remove_channel_by_deletemsg(struct gossmap *map, u64 del_off)
@@ -677,7 +673,7 @@ static bool csum_matches(const struct gossmap *map,
 /* Returns false only if must_be_clean is true. */
 static bool map_catchup(struct gossmap *map, bool must_be_clean, bool *changed)
 {
-	size_t reclen;
+	size_t reclen, num_bad_cupdates = 0;
 
 	*changed = false;
 
@@ -749,7 +745,7 @@ static bool map_catchup(struct gossmap *map, bool must_be_clean, bool *changed)
 			if (redundant && must_be_clean)
 				return false;
 		} else if (type == WIRE_CHANNEL_UPDATE)
-			update_channel(map, off);
+			num_bad_cupdates += update_channel(map, off);
 		else if (type == WIRE_GOSSIP_STORE_DELETE_CHAN)
 			remove_channel_by_deletemsg(map, off);
 		else if (type == WIRE_NODE_ANNOUNCEMENT)
@@ -775,6 +771,12 @@ static bool map_catchup(struct gossmap *map, bool must_be_clean, bool *changed)
 		*changed = true;
 	}
 
+	if (num_bad_cupdates != 0)
+		map->logcb(map->cbarg,
+			   LOG_DBG,
+			   "Got %zu bad cupdates, ignoring them (expected on mainnet)",
+			   num_bad_cupdates);
+
 	return true;
 }
 
@@ -1168,7 +1170,7 @@ void gossmap_apply_localmods(struct gossmap *map,
 			off = insert_local_space(&map->local_updates, tal_bytelen(cupdatemsg));
 			memcpy(map->local_updates + off, cupdatemsg, tal_bytelen(cupdatemsg));
 			chan->cupdate_off[h] = map->map_size + tal_bytelen(map->local_announces) + off;
-			fill_from_update(map, &scidd, &chan->half[h], chan->cupdate_off[h], NULL, NULL);
+			fill_from_update(map, &scidd, &chan->half[h], chan->cupdate_off[h]);
 
 			/* We wrote the right update, correct? */
 			assert(short_channel_id_eq(scidd.scid, mod->scid));

contrib/msggen/msggen/schema.json

@@ -15010,7 +15010,7 @@
       "$schema": "../rpc-schema-draft.json",
       "type": "object",
       "rpc": "getlog",
-      "title": "Command to show logs.",
+      "title": "Command to show recent logs.",
       "description": [
         "The **getlog** the RPC command to show logs, with optional log *level*."
       ],
@@ -15184,8 +15184,7 @@
                     "required": [
                       "time",
                       "source",
-                      "log",
-                      "data"
+                      "log"
                     ],
                     "properties": {
                       "type": {},

doc/schemas/getlog.json

@@ -2,7 +2,7 @@
   "$schema": "../rpc-schema-draft.json",
   "type": "object",
   "rpc": "getlog",
-  "title": "Command to show logs.",
+  "title": "Command to show recent logs.",
   "description": [
     "The **getlog** the RPC command to show logs, with optional log *level*."
   ],
@@ -176,8 +176,7 @@
                 "required": [
                   "time",
                   "source",
-                  "log",
-                  "data"
+                  "log"
                 ],
                 "properties": {
                   "type": {},

gossipd/gossmap_manage.c

@@ -703,9 +703,16 @@ void gossmap_manage_handle_get_txout_reply(struct gossmap_manage *gm, const u8 *
 	 *    - MUST ignore the message.
 	 */
 	if (tal_count(outscript) == 0) {
-		peer_warning(gm, pca->source_peer,
-			     "channel_announcement: no unspent txout %s",
-			     fmt_short_channel_id(tmpctx, scid));
+		/* Don't flood them: this happens with pre-25.12 CLN
+		 * nodes, which lost their marbles about some old
+		 * UTXOs. */
+		static struct timemono prev;
+		if (time_greater(timemono_since(prev), time_from_sec(1))) {
+			peer_warning(gm, pca->source_peer,
+				     "channel_announcement: no unspent txout %s",
+				     fmt_short_channel_id(tmpctx, scid));
+			prev = time_mono();
+		}
 		goto bad;
 	}
 

lightningd/lightningd.c

@@ -213,11 +213,11 @@ static struct lightningd *new_lightningd(const tal_t *ctx)
 	 * who talk to us about long-closed channels. */
 	ld->closed_channels = new_htable(ld, closed_channel_map);
 
-	/*~ We have a multi-entry log-book infrastructure: we define a 10MB log
-	 * book to hold all the entries (and trims as necessary), and multiple
+	/*~ We have a multi-entry log-book infrastructure: we define a 16MB log
+	 * book to hold all the entries in a circular buffer, and multiple
 	 * log objects which each can write into it, each with a unique
 	 * prefix. */
-	ld->log_book = new_log_book(ld, 10*1024*1024);
+	ld->log_book = new_log_book(ld);
 	/*~ Note the tal context arg (by convention, the first argument to any
 	 * allocation function): ld->log will be implicitly freed when ld
 	 * is. */