pytest: protect against bad gossip messages from mining confirms too …

…fast.

If we fund a channel between two nodes, then mine all the blocks to
announce it, any other nodes may see the announcement before the
blocks, causing CI to complain about "bad gossip":

```
lightningd-4: 2022-01-25T22:33:25.468Z DEBUG   032cf15d1ad9c4a08d26eab1918f732d8ef8fdc6abb9640bf3db174372c491304e-gossipd: Ignoring future channel_announcment for 113x1x1 (current block 112)
lightningd-4: 2022-01-25T22:33:25.468Z DEBUG   032cf15d1ad9c4a08d26eab1918f732d8ef8fdc6abb9640bf3db174372c491304e-gossipd: Bad gossip order: WIRE_CHANNEL_UPDATE before announcement 113x1x1/0
lightningd-4: 2022-01-25T22:33:25.468Z DEBUG   032cf15d1ad9c4a08d26eab1918f732d8ef8fdc6abb9640bf3db174372c491304e-gossipd: Bad gossip order: WIRE_CHANNEL_UPDATE before announcement 113x1x1/1
lightningd-4: 2022-01-25T22:33:25.468Z DEBUG   032cf15d1ad9c4a08d26eab1918f732d8ef8fdc6abb9640bf3db174372c491304e-gossipd: Bad gossip order: WIRE_NODE_ANNOUNCEMENT before announcement 032cf15d1ad9c4a08d26eab1918f732d8ef8fdc6abb9640bf3db174372c491304e
```

Add a new helper for this case, and use it where there are more than 2 nodes.

Cleans up test_routing_gossip and a few other places which did this manually.

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

contrib/pyln-testing/pyln/testing/utils.py

@@ -118,6 +118,17 @@ def sync_blockheight(bitcoind, nodes):
         wait_for(lambda: n.rpc.getinfo()['blockheight'] == height)
 
 
+def mine_funding_to_announce(bitcoind, nodes, num_blocks=5, wait_for_mempool=0):
+    """Mine blocks so a channel can be announced (5, if it's already
+mined), but make sure we don't leave nodes behind who will reject the
+announcement.  Not needed if there are only two nodes.
+
+    """
+    bitcoind.generate_block(num_blocks - 1, wait_for_mempool)
+    sync_blockheight(bitcoind, nodes)
+    bitcoind.generate_block(1)
+
+
 def wait_channel_quiescent(n1, n2):
     wait_for(lambda: only_one(only_one(n1.rpc.listpeers(n2.info['id'])['peers'])['channels'])['htlcs'] == [])
     wait_for(lambda: only_one(only_one(n2.rpc.listpeers(n1.info['id'])['peers'])['channels'])['htlcs'] == [])

tests/test_closing.py

@@ -8,7 +8,7 @@
     account_balance, first_channel_id, closing_fee, TEST_NETWORK,
     scriptpubkey_addr, calc_lease_fee, EXPERIMENTAL_FEATURES,
     check_utxos_channel, anchor_expected, check_coin_moves,
-    check_balance_snaps
+    check_balance_snaps, mine_funding_to_announce
 )
 
 import os
@@ -281,7 +281,7 @@ def test_closing_different_fees(node_factory, bitcoind, executor):
         # Technically, this is async to fundchannel returning.
         l1.daemon.wait_for_log('sendrawtx exit 0')
 
-    bitcoind.generate_block(6)
+    mine_funding_to_announce(bitcoind, peers, num_blocks=6)
 
     # Now wait for them all to hit normal state, do payments
     l1.daemon.wait_for_logs(['update for channel .* now ACTIVE'] * num_peers
@@ -349,7 +349,8 @@ def test_closing_specified_destination(node_factory, bitcoind, chainparams):
     l1.pay(l3, 100000000)
     l1.pay(l4, 100000000)
 
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3, l4])
+
     addr = chainparams['example_addr']
     l1.rpc.close(chan12, None, addr)
     l1.rpc.call('close', {'id': chan13, 'destination': addr})
@@ -2160,7 +2161,7 @@ def test_onchain_middleman_simple(node_factory, bitcoind):
     channel_id = first_channel_id(l1, l2)
 
     # Make sure routes finalized.
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
     l1.wait_channel_active(c23)
 
     # Give l1 some money to play with.
@@ -2280,7 +2281,7 @@ def test_onchain_middleman_their_unilateral_in(node_factory, bitcoind):
     channel_id = first_channel_id(l1, l2)
 
     # Make sure routes finalized.
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
     l1.wait_channel_active(c23)
 
     # Make sure l3 sees gossip for channel now; it can get upset

tests/test_connection.py

@@ -11,7 +11,7 @@
     expected_channel_features,
     check_coin_moves, first_channel_id, account_balance, basic_fee,
     scriptpubkey_addr,
-    EXPERIMENTAL_FEATURES
+    EXPERIMENTAL_FEATURES, mine_funding_to_announce
 )
 from pyln.testing.utils import SLOW_MACHINE, VALGRIND, EXPERIMENTAL_DUAL_FUND, FUNDAMOUNT
 
@@ -2556,7 +2556,7 @@ def test_disconnectpeer(node_factory, bitcoind):
 
     # Fund channel l1 -> l3
     l1.fundchannel(l3, 10**6)
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
 
     # disconnecting a non gossiping peer results in error
     with pytest.raises(RpcError, match=r'Peer is in state CHANNELD_NORMAL'):
@@ -2945,11 +2945,9 @@ def test_restart_many_payments(node_factory, bitcoind):
         # OK to use change from previous fundings
         l1.rpc.fundchannel(n.info['id'], 10**6, minconf=0)
 
-    # Now mine them, get scids; make sure they all see the first block
-    # otherwise they may complain about channel_announcement from the future.
-    bitcoind.generate_block(1, wait_for_mempool=num * 2)
-    sync_blockheight(bitcoind, [l1] + nodes)
-    bitcoind.generate_block(5)
+    # Now mine them, get scids
+    mine_funding_to_announce(bitcoind, [l1] + nodes,
+                             num_blocks=6, wait_for_mempool=num * 2)
 
     wait_for(lambda: [only_one(n.rpc.listpeers()['peers'])['channels'][0]['state'] for n in nodes] == ['CHANNELD_NORMAL'] * len(nodes))
 

tests/test_gossip.py

@@ -5,7 +5,8 @@
 from pyln.client import RpcError, Millisatoshi
 from utils import (
     DEVELOPER, wait_for, TIMEOUT, only_one, sync_blockheight,
-    expected_node_features, COMPAT, EXPERIMENTAL_FEATURES
+    expected_node_features, COMPAT, EXPERIMENTAL_FEATURES,
+    mine_funding_to_announce
 )
 
 import json
@@ -37,7 +38,7 @@ def test_gossip_pruning(node_factory, bitcoind):
     scid1, _ = l1.fundchannel(l2, 10**6)
     scid2, _ = l2.fundchannel(l3, 10**6)
 
-    bitcoind.generate_block(6)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
 
     # Channels should be activated locally
     wait_for(lambda: [c['active'] for c in l1.rpc.listchannels()['channels']] == [True] * 4)
@@ -201,7 +202,7 @@ def test_announce_and_connect_via_dns(node_factory, bitcoind):
     l3.rpc.connect(l2.info['id'], 'localhost', l2.port)
     l4.rpc.connect(l2.info['id'], 'localhost', l2.port)
     scid, _ = l1.fundchannel(l2, 10**6)
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
 
     # wait until l3 and l4 see l1 via gossip with announced addresses
     wait_for(lambda: len(l3.rpc.listnodes(l1.info['id'])['nodes']) == 1)
@@ -252,7 +253,7 @@ def test_gossip_timestamp_filter(node_factory, bitcoind, chainparams):
 
     # Make a public channel.
     chan12, _ = l1.fundchannel(l2, 10**5)
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3, l4])
 
     l3.wait_for_channel_updates([chan12])
     after_12 = int(time.time())
@@ -334,7 +335,7 @@ def test_connect_by_gossip(node_factory, bitcoind):
 
     # Nodes are gossiped only if they have channels
     chanid, _ = l2.fundchannel(l3, 10**6)
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
 
     # Let channel reach announcement depth
     l2.wait_channel_active(chanid)
@@ -442,7 +443,7 @@ def test_gossip_jsonrpc(node_factory):
 
 
 @pytest.mark.developer("Too slow without --dev-fast-gossip")
-def test_gossip_badsig(node_factory):
+def test_gossip_badsig(node_factory, bitcoind):
     """Make sure node announcement signatures are ok.
 
     This is a smoke test to see if signatures fail. This used to be the case
@@ -460,7 +461,7 @@ def test_gossip_badsig(node_factory):
     l2.fundchannel(l3, 10**6)
 
     # Wait for route propagation.
-    l1.bitcoin.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
     l1.daemon.wait_for_log('Received node_announcement for node {}'
                            .format(l3.info['id']))
     assert not l1.daemon.is_in_log('signature verification failed')
@@ -517,7 +518,7 @@ def test_gossip_persistence(node_factory, bitcoind):
     scid23, _ = l2.fundchannel(l3, 10**6)
 
     # Make channels public, except for l3 -> l4, which is kept local-only for now
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3, l4])
     scid34, _ = l3.fundchannel(l4, 10**6)
     bitcoind.generate_block(1)
 
@@ -610,7 +611,7 @@ def test_gossip_no_empty_announcements(node_factory, bitcoind, chainparams):
                                              fundchannel=False)
 
     l3.fundchannel(l4, 10**5)
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3, l4])
 
     # l2 sends CHANNEL_ANNOUNCEMENT to l1, then disconnects/
     l2.daemon.wait_for_log('dev_disconnect')
@@ -644,20 +645,16 @@ def test_gossip_no_empty_announcements(node_factory, bitcoind, chainparams):
 def test_routing_gossip(node_factory, bitcoind):
     nodes = node_factory.get_nodes(5)
 
-    sync_blockheight(bitcoind, nodes)
     for i in range(len(nodes) - 1):
         src, dst = nodes[i], nodes[i + 1]
         src.rpc.connect(dst.info['id'], 'localhost', dst.port)
         src.openchannel(dst, 25000, confirm=False, wait_for_announce=False)
-        sync_blockheight(bitcoind, nodes)
 
-    # Avoid "bad gossip" caused by future announcements (a node below
-    # confirmation height receiving and ignoring the announcement,
-    # thus marking followup messages as bad).
-    sync_blockheight(bitcoind, nodes)
+    # openchannel calls fundwallet which mines a block; so first channel
+    # is 4 deep, last is unconfirmed.
 
     # Allow announce messages.
-    bitcoind.generate_block(6)
+    mine_funding_to_announce(bitcoind, nodes, num_blocks=6, wait_for_mempool=1)
 
     # Deep check that all channels are in there
     comb = []
@@ -691,17 +688,15 @@ def test_gossip_query_channel_range(node_factory, bitcoind, chainparams):
     l2.fundwallet(10**6)
 
     num_tx = len(bitcoind.rpc.getrawmempool())
+    # We want these one block apart.
     l1.rpc.fundchannel(l2.info['id'], 10**5)['tx']
-    wait_for(lambda: len(bitcoind.rpc.getrawmempool()) == num_tx + 1)
-    bitcoind.generate_block(1)
-
-    num_tx = len(bitcoind.rpc.getrawmempool())
+    bitcoind.generate_block(wait_for_mempool=num_tx + 1)
+    sync_blockheight(bitcoind, [l1, l2, l3, l4])
     l2.rpc.fundchannel(l3.info['id'], 10**5)['tx']
-    wait_for(lambda: len(bitcoind.rpc.getrawmempool()) == num_tx + 1)
-    bitcoind.generate_block(1)
-
     # Get them both to gossip depth.
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3, l4],
+                             num_blocks=6,
+                             wait_for_mempool=1)
 
     # Make sure l2 has received all the gossip.
     l2.daemon.wait_for_logs(['Received node_announcement for node ' + l1.info['id'],
@@ -874,7 +869,7 @@ def test_gossip_query_channel_range(node_factory, bitcoind, chainparams):
 
     # This should actually be large enough for zlib to kick in!
     scid34, _ = l3.fundchannel(l4, 10**5)
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3, l4])
     l2.daemon.wait_for_log('Received node_announcement for node ' + l4.info['id'])
 
     # Restore infinite encode size.
@@ -924,12 +919,6 @@ def test_report_routing_failure(node_factory, bitcoind):
     # Finally the only possible path is
     # l1-l2-l3-l4.
 
-    def fund_from_to_payer(lsrc, ldst, lpayer):
-        lsrc.rpc.connect(ldst.info['id'], 'localhost', ldst.port)
-        c, _ = lsrc.fundchannel(ldst, 10000000)
-        bitcoind.generate_block(5)
-        lpayer.wait_for_channel_updates([c])
-
     # Setup
     # Construct lightningd
     l1, l2, l3, l4 = node_factory.get_nodes(4)
@@ -946,7 +935,7 @@ def fund_from_to_payer(lsrc, ldst, lpayer):
                                       dst.daemon.lightning_dir))
         c, _ = src.fundchannel(dst, 10**6)
         channels.append(c)
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3, l4])
 
     for c in channels:
         l1.wait_channel_active(c)
@@ -982,7 +971,7 @@ def test_query_short_channel_id(node_factory, bitcoind, chainparams):
     # Make channels public.
     scid12, _ = l1.fundchannel(l2, 10**5)
     scid23, _ = l2.fundchannel(l3, 10**5)
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
 
     # It will know about everything.
     l1.daemon.wait_for_log('Received node_announcement for node {}'.format(l3.info['id']))
@@ -1369,7 +1358,7 @@ def test_gossip_notices_close(node_factory, bitcoind):
     node_factory.join_nodes([l2, l3])
     l1.rpc.connect(l2.info['id'], 'localhost', l2.port)
 
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
 
     # Make sure l1 learns about channel and nodes.
     wait_for(lambda: len(l1.rpc.listchannels()['channels']) == 2)
@@ -1468,7 +1457,7 @@ def test_getroute_exclude(node_factory, bitcoind):
     # Now, create an alternate (better) route.
     l2.rpc.connect(l4.info['id'], 'localhost', l4.port)
     scid, _ = l2.fundchannel(l4, 1000000, wait_for_active=False)
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3, l4, l5])
 
     # We don't wait above, because we care about it hitting l1.
     l1.daemon.wait_for_logs([r'update for channel {}/0 now ACTIVE'
@@ -1505,7 +1494,7 @@ def test_getroute_exclude(node_factory, bitcoind):
     scid15, _ = l1.fundchannel(l5, 1000000, wait_for_active=False)
     l5.rpc.connect(l4.info['id'], 'localhost', l4.port)
     scid54, _ = l5.fundchannel(l4, 1000000, wait_for_active=False)
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3, l4, l5])
 
     # We don't wait above, because we care about it hitting l1.
     l1.daemon.wait_for_logs([r'update for channel {}/0 now ACTIVE'
@@ -1589,7 +1578,7 @@ def setup_gossip_store_test(node_factory, bitcoind):
     scid23, _ = l2.fundchannel(l3, 10**6)
 
     # Have that channel announced.
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
     # Make sure we've got node_announcements
     wait_for(lambda: ['alias' in n for n in l2.rpc.listnodes()['nodes']] == [True, True])
 
@@ -2115,7 +2104,7 @@ def test_topology_leak(node_factory, bitcoind):
     l1, l2, l3 = node_factory.line_graph(3)
 
     l1.rpc.listchannels()
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3])
 
     # Wait until l1 sees all the channels.
     wait_for(lambda: len(l1.rpc.listchannels()['channels']) == 4)

tests/test_invoices.py

@@ -1,7 +1,7 @@
 from fixtures import *  # noqa: F401,F403
 from fixtures import TEST_NETWORK
 from pyln.client import RpcError, Millisatoshi
-from utils import only_one, wait_for, wait_channel_quiescent
+from utils import only_one, wait_for, wait_channel_quiescent, mine_funding_to_announce
 
 
 import pytest
@@ -221,7 +221,7 @@ def test_invoice_routeboost_private(node_factory, bitcoind):
     l0 = node_factory.get_node()
     l0.rpc.connect(l1.info['id'], 'localhost', l1.port)
     scid_dummy, _ = l0.fundchannel(l1, 2 * (10**5))
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l0, l1, l2, l3])
 
     # Make sure channel is totally public.
     wait_for(lambda: [c['public'] for c in l2.rpc.listchannels(scid_dummy)['channels']] == [True, True])
@@ -285,7 +285,7 @@ def test_invoice_routeboost_private(node_factory, bitcoind):
     # the exposure of private channels.
     l3.rpc.connect(l2.info['id'], 'localhost', l2.port)
     scid2, _ = l3.fundchannel(l2, (10**5))
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l0, l1, l2, l3])
 
     # Make sure channel is totally public.
     wait_for(lambda: [c['public'] for c in l2.rpc.listchannels(scid2)['channels']] == [True, True])

tests/test_misc.py

@@ -7,7 +7,7 @@
 from threading import Event
 from pyln.testing.utils import (
     DEVELOPER, TIMEOUT, VALGRIND, DEPRECATED_APIS, sync_blockheight, only_one,
-    wait_for, TailableProc, env
+    wait_for, TailableProc, env, mine_funding_to_announce
 )
 from utils import (
     account_balance, scriptpubkey_addr, check_coin_moves
@@ -2291,7 +2291,7 @@ def test_listforwards(node_factory, bitcoind):
     c24, _ = l2.fundchannel(l4, 10**5)
 
     # Wait until channels are active
-    bitcoind.generate_block(5)
+    mine_funding_to_announce(bitcoind, [l1, l2, l3, l4])
     l1.wait_channel_active(c23)
 
     # successful payments