From 87fc3439c4081ec8ba9e3855bcb43d88c4732a28 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 6 Jun 2017 09:17:10 +0930 Subject: [PATCH] test_lightningd.py: fix obscure corner case in gossip. I actually hit this very hard to reproduce race: if we haven't process the channeld message when block #6 comes in, we won't send the gossip message. We wait for logs, but don't generate new blocks, and timeout on l1.daemon.wait_for_log('peer_out WIRE_ANNOUNCEMENT_SIGNATURES'). The solution, which also tests that we don't send announcement signatures immediately, is to generate a single block, wait for CHANNELD_NORMAL, then (in gossip tests), generate 5 more. Signed-off-by: Rusty Russell --- lightningd/gossip/gossip.c | 9 ++++++--- lightningd/peer_control.c | 4 ++++ tests/test_lightningd.py | 12 +++++++++++- 3 files changed, 21 insertions(+), 4 deletions(-) diff --git a/lightningd/gossip/gossip.c b/lightningd/gossip/gossip.c index 37a1144c7..44c83cc09 100644 --- a/lightningd/gossip/gossip.c +++ b/lightningd/gossip/gossip.c @@ -612,16 +612,19 @@ static struct io_plan *resolve_channel_req(struct io_conn *conn, status_failed(WIRE_GOSSIPSTATUS_BAD_REQUEST, "Unable to parse resolver request"); - status_trace("Attempting to resolve channel %s", - type_to_string(trc, struct short_channel_id, &scid)); - nc = get_connection_by_scid(daemon->rstate, &scid, 0); if (!nc) { + status_trace("Failed to resolve channel %s", + type_to_string(trc, struct short_channel_id, &scid)); keys = NULL; } else { keys = tal_arr(msg, struct pubkey, 2); keys[0] = nc->src->id; keys[1] = nc->dst->id; + status_trace("Resolved channel %s %s<->%s", + type_to_string(trc, struct short_channel_id, &scid), + type_to_string(trc, struct pubkey, &keys[0]), + type_to_string(trc, struct pubkey, &keys[1])); } daemon_conn_send(&daemon->master, take(towire_gossip_resolve_channel_reply(msg, keys))); diff --git a/lightningd/peer_control.c b/lightningd/peer_control.c index 3e1321c1d..c7abafc62 100644 --- a/lightningd/peer_control.c +++ b/lightningd/peer_control.c @@ -662,6 +662,10 @@ static enum watch_result funding_announce_cb(struct peer *peer, return KEEP_WATCHING; } if (peer->state != CHANNELD_NORMAL || !peer->owner) { + log_debug(peer->ld->log, + "Funding tx announce ready, but peer state %s %s", + peer_state_name(peer->state), + peer->owner ? peer->owner->name : "unowned"); return KEEP_WATCHING; } subd_send_msg(peer->owner, diff --git a/tests/test_lightningd.py b/tests/test_lightningd.py index b36f3231f..0e2b30c1d 100644 --- a/tests/test_lightningd.py +++ b/tests/test_lightningd.py @@ -183,7 +183,7 @@ class LightningDTests(BaseLightningDTests): # Technically, this is async to fundchannel. l1.daemon.wait_for_log('sendrawtx exit 0') - l1.bitcoin.rpc.generate(6) + l1.bitcoin.rpc.generate(1) l1.daemon.wait_for_log('-> CHANNELD_NORMAL') l2.daemon.wait_for_log('-> CHANNELD_NORMAL') @@ -307,6 +307,10 @@ class LightningDTests(BaseLightningDTests): self.fund_channel(l1,l2,10**5) + # Shouldn't send announce signatures until 6 deep. + assert not l1.daemon.is_in_log('peer_out WIRE_ANNOUNCEMENT_SIGNATURES') + + l1.bitcoin.rpc.generate(5) l1.daemon.wait_for_log('peer_out WIRE_ANNOUNCEMENT_SIGNATURES') l1.daemon.wait_for_log('peer_in WIRE_ANNOUNCEMENT_SIGNATURES') @@ -366,6 +370,9 @@ class LightningDTests(BaseLightningDTests): src.rpc.connect('localhost', dst.info['port'], dst.info['id']) src.openchannel(dst, 20000) + # Allow announce messages. + l1.bitcoin.rpc.generate(5) + def settle_gossip(n): """Wait for gossip to settle at the node """ @@ -407,6 +414,9 @@ class LightningDTests(BaseLightningDTests): self.fund_channel(l1, l2, 10**6) self.fund_channel(l2, l3, 10**6) + # Allow announce messages. + l1.bitcoin.rpc.generate(5) + # If they're at different block heights we can get spurious errors. sync_blockheight(l1, l2, l3)