From f15e2506ca14118dd57a85445414e1e346afdc8e Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Thu, 27 Jul 2023 14:15:53 +0930 Subject: [PATCH] pytest: fix flake in test_gossip_store_compact_on_load. We can have almost arbitrary re-transmissions of private updates, looking at the decode: in this case, instead of the expected: ``` DELETED: private channel_announcement (scid23) DELETED: private channel_update (scid23/0) DELETED: private channel_update (scid23/1) delete channel (scid23) channel_announcement (scid23) channel_amount DELETED: channel_update (scid23/0) DELETED: channel_update (scid23/1) node_announcement node_announcement channel_update (scid23) private channel_announcement (scid12) DELETED: private channel_update (scid12/0) DELETED: private channel_update (scid12/1) channel_update (scid23) private_channel_update (scid12) private_channel_update (scid12) ``` We had: ``` DELETED: private channel_announcement DELETED: private channel_update DELETED: private channel_update DELETED: private channel_update DELETED: private channel_update channel_announcement channel_amount DELETED: channel_update DELETED: channel_update node_announcement node_announcement channel_update private channel_announcement DELETED: private channel_update DELETED: private channel_update channel_update private channel_update private channel_update ``` Which means we deleted 9, and hence failed: ``` @pytest.mark.developer("gossip without DEVELOPER=1 is slow") def test_gossip_store_compact_on_load(node_factory, bitcoind): l2 = setup_gossip_store_test(node_factory, bitcoind) gs_path = os.path.join(l2.daemon.lightning_dir, TEST_NETWORK, 'gossip_store') gs = subprocess.run(['devtools/dump-gossipstore', '--print-deleted', gs_path], check=True, timeout=TIMEOUT, stdout=subprocess.PIPE) print(gs.stdout.decode()) l2.restart() > wait_for(lambda: l2.daemon.is_in_log(r'gossip_store_compact_offline: [5-8] deleted, 9 copied')) tests/test_gossip.py:1776: ``` --- tests/test_gossip.py | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/tests/test_gossip.py b/tests/test_gossip.py index ae70b000c..cc87b4100 100644 --- a/tests/test_gossip.py +++ b/tests/test_gossip.py @@ -14,6 +14,7 @@ import logging import math import os import pytest +import re import struct import subprocess import time @@ -1773,9 +1774,14 @@ def test_gossip_store_compact_on_load(node_factory, bitcoind): l2.restart() - wait_for(lambda: l2.daemon.is_in_log(r'gossip_store_compact_offline: [5-8] deleted, 9 copied')) + # These appear before we're fully started, so will already in log: + line = l2.daemon.is_in_log(r'gossip_store_compact_offline: .* deleted, 9 copied') + m = re.search(r'gossip_store_compact_offline: (.*) deleted', line) + # We can have private re-tranmissions, but at minumum we had a deleted private + # channel message and two private updates, then two deleted updates. + assert int(m.group(1)) >= 5 - wait_for(lambda: l2.daemon.is_in_log(r'gossip_store: Read 2/4/2/0 cannounce/cupdate/nannounce/cdelete from store \(0 deleted\) in [0-9]* bytes')) + assert l2.daemon.is_in_log(r'gossip_store: Read 2/4/2/0 cannounce/cupdate/nannounce/cdelete from store \(0 deleted\) in [0-9]* bytes') def test_gossip_announce_invalid_block(node_factory, bitcoind):