Skip to content

Commit

Permalink
gossipd: extra debugging when inject fails.
Browse files Browse the repository at this point in the history
test_closing_different_fees fails:

```
2024-10-14T08:43:30.2733614Z
2024-10-14T08:43:30.2734133Z         # Now wait for them all to hit normal state, do payments
2024-10-14T08:43:30.2735205Z >       l1.daemon.wait_for_logs(['update for channel .* now ACTIVE'] * num_peers
2024-10-14T08:43:30.2736233Z                                 + ['to CHANNELD_NORMAL'] * num_peers)
2024-10-14T08:43:30.2736725Z
2024-10-14T08:43:30.2736903Z tests/test_closing.py:230:
...
2024-10-14T08:43:30.2761325Z E                   TimeoutError: Unable to find "[re.compile('update for channel .* now ACTIVE')]" in logs.
```

For some reason one of the channel_update injections does *not* evoke this message
from gossipd...

Changelog-None: debug!
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
  • Loading branch information
rustyrussell committed Oct 14, 2024
1 parent c7189f6 commit 93fb038
Show file tree
Hide file tree
Showing 3 changed files with 24 additions and 5 deletions.
5 changes: 4 additions & 1 deletion gossipd/gossipd.c
Original file line number Diff line number Diff line change
Expand Up @@ -538,7 +538,10 @@ static void inject_gossip(struct daemon *daemon, const u8 *msg)
case WIRE_CHANNEL_UPDATE:
err = gossmap_manage_channel_update(tmpctx,
daemon->gm,
take(goss), NULL);
goss, NULL);
if (err)
status_debug("update %s gave error %s",
tal_hex(tmpctx, goss), err);
break;
default:
err = tal_fmt(tmpctx, "unknown gossip type %i",
Expand Down
20 changes: 18 additions & 2 deletions gossipd/gossmap_manage.c
Original file line number Diff line number Diff line change
Expand Up @@ -734,8 +734,12 @@ static const char *process_channel_update(const tal_t *ctx,
chan = gossmap_find_chan(gossmap, &scid);
if (!chan) {
/* Did we explicitly reject announce? Ignore completely. */
if (in_txout_failures(gm->txf, scid))
if (in_txout_failures(gm->txf, scid)) {
if (!source_peer)
status_debug("Previously-rejected announce for %s",
fmt_short_channel_id(tmpctx, scid));
return NULL;
}

/* Seeker may want to ask about this. */
query_unknown_channel(gm->daemon, source_peer, scid);
Expand Down Expand Up @@ -767,6 +771,9 @@ static const char *process_channel_update(const tal_t *ctx,
u32 prev_timestamp
= gossip_store_get_timestamp(gm->daemon->gs, chan->cupdate_off[dir]);
if (prev_timestamp >= timestamp) {
if (!source_peer)
status_debug("Too-old update for %s",
fmt_short_channel_id(tmpctx, scid));
/* Too old, ignore */
return NULL;
}
Expand Down Expand Up @@ -846,11 +853,17 @@ const char *gossmap_manage_channel_update(const tal_t *ctx,
}

/* Don't accept ancient or far-future timestamps. */
if (!timestamp_reasonable(gm->daemon, timestamp))
if (!timestamp_reasonable(gm->daemon, timestamp)) {
if (!source_peer)
status_debug("Unreasonable timestamp in %s", tal_hex(tmpctx, update));
return NULL;
}

/* Still waiting? */
if (map_get(&gm->pending_ann_map, scid)) {
if (!source_peer)
status_debug("Enqueueing update for announcne %s",
tal_hex(tmpctx, update));
enqueue_cupdate(&gm->pending_cupdates,
scid,
&signature,
Expand All @@ -869,6 +882,9 @@ const char *gossmap_manage_channel_update(const tal_t *ctx,

/* Too early? */
if (map_get(&gm->early_ann_map, scid)) {
if (!source_peer)
status_debug("Enqueueing update for too early %s",
tal_hex(tmpctx, update));
enqueue_cupdate(&gm->early_cupdates,
scid,
&signature,
Expand Down
4 changes: 2 additions & 2 deletions tests/test_gossip.py
Original file line number Diff line number Diff line change
Expand Up @@ -1811,8 +1811,8 @@ def test_addgossip(node_factory):
opts={'log-level': 'io'})

# We should get two node_announcements, one channel_announcement, and two
# channel_update.
l3 = node_factory.get_node()
# channel_update. We deliberately inject bad gossip!
l3 = node_factory.get_node(allow_bad_gossip=True)

# 0x0100 = channel_announcement
# 0x0102 = channel_update
Expand Down

0 comments on commit 93fb038

Please sign in to comment.