From f3159ec4acd1013427c292038b88071b868ab1ff Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Wed, 3 Feb 2021 14:41:09 +1030 Subject: [PATCH] pytest: detect warnings, too. Since we turned many errors into warnings, we want our tests to fail when they happen unexpectedly. We make WARNING clear in the strings we print, too, to help out. Signed-off-by: Rusty Russell --- contrib/pyln-testing/pyln/testing/fixtures.py | 1 + contrib/pyln-testing/pyln/testing/utils.py | 9 +++++++-- lightningd/peer_control.c | 2 +- tests/test_closing.py | 11 ++++++++-- tests/test_connection.py | 6 ++++-- tests/test_misc.py | 2 +- tests/test_pay.py | 5 +++-- tests/test_plugin.py | 20 +++++++++++++------ 8 files changed, 40 insertions(+), 16 deletions(-) diff --git a/contrib/pyln-testing/pyln/testing/fixtures.py b/contrib/pyln-testing/pyln/testing/fixtures.py index c02844890..6f1d96b0e 100644 --- a/contrib/pyln-testing/pyln/testing/fixtures.py +++ b/contrib/pyln-testing/pyln/testing/fixtures.py @@ -229,6 +229,7 @@ def node_factory(request, directory, test_name, bitcoind, executor, db_provider, map_node_error(nf.nodes, printValgrindErrors, "reported valgrind errors") map_node_error(nf.nodes, printCrashLog, "had crash.log files") map_node_error(nf.nodes, lambda n: not n.allow_broken_log and n.daemon.is_in_log(r'\*\*BROKEN\*\*'), "had BROKEN messages") + map_node_error(nf.nodes, lambda n: not n.allow_warning and n.daemon.is_in_log(r' WARNING:'), "had warning messages") map_node_error(nf.nodes, checkReconnect, "had unexpected reconnections") map_node_error(nf.nodes, checkBadGossip, "had bad gossip messages") map_node_error(nf.nodes, lambda n: n.daemon.is_in_log('Bad reestablish'), "had bad reestablish") diff --git a/contrib/pyln-testing/pyln/testing/utils.py b/contrib/pyln-testing/pyln/testing/utils.py index cdd1ea9de..944fd2c86 100644 --- a/contrib/pyln-testing/pyln/testing/utils.py +++ b/contrib/pyln-testing/pyln/testing/utils.py @@ -619,8 +619,11 @@ class PrettyPrintingLightningRpc(LightningRpc): class LightningNode(object): def __init__(self, node_id, lightning_dir, bitcoind, executor, valgrind, may_fail=False, - may_reconnect=False, allow_broken_log=False, - allow_bad_gossip=False, db=None, port=None, disconnect=None, random_hsm=None, options=None, + may_reconnect=False, + allow_broken_log=False, + allow_warning=False, + allow_bad_gossip=False, + db=None, port=None, disconnect=None, random_hsm=None, options=None, **kwargs): self.bitcoin = bitcoind self.executor = executor @@ -628,6 +631,7 @@ class LightningNode(object): self.may_reconnect = may_reconnect self.allow_broken_log = allow_broken_log self.allow_bad_gossip = allow_bad_gossip + self.allow_warning = allow_warning self.db = db # Assume successful exit @@ -1207,6 +1211,7 @@ class NodeFactory(object): 'disconnect', 'may_fail', 'allow_broken_log', + 'allow_warning', 'may_reconnect', 'random_hsm', 'feerates', diff --git a/lightningd/peer_control.c b/lightningd/peer_control.c index 439f3e32f..7f87bf549 100644 --- a/lightningd/peer_control.c +++ b/lightningd/peer_control.c @@ -396,7 +396,7 @@ void channel_errmsg(struct channel *channel, * and we would close the channel on them. We now support warnings * for this case. */ if (warning) { - channel_fail_reconnect_later(channel, "%s: (ignoring) %s", + channel_fail_reconnect_later(channel, "%s WARNING: %s", channel->owner->name, desc); return; } diff --git a/tests/test_closing.py b/tests/test_closing.py index 42d37b04b..b5376211f 100644 --- a/tests/test_closing.py +++ b/tests/test_closing.py @@ -1784,7 +1784,11 @@ def test_listfunds_after_their_unilateral(node_factory, bitcoind): Make sure we show the address. """ coin_mvt_plugin = os.path.join(os.getcwd(), 'tests/plugins/coin_movements.py') - l1, l2 = node_factory.line_graph(2, opts={'plugin': coin_mvt_plugin}) + # FIXME: We can get warnings from unilteral changes, since we treat + # such errors a soft because LND. + l1, l2 = node_factory.line_graph(2, opts=[{'plugin': coin_mvt_plugin, + "allow_warning": True}, + {'plugin': coin_mvt_plugin}]) channel_id = first_channel_id(l1, l2) # listfunds will show 1 output change, and channels. @@ -2523,7 +2527,10 @@ def test_shutdown(node_factory): @flaky @unittest.skipIf(not DEVELOPER, "needs to set upfront_shutdown_script") def test_option_upfront_shutdown_script(node_factory, bitcoind, executor): - l1 = node_factory.get_node(start=False) + # There's a workaround in channeld, that it treats incoming errors + # before both sides are locked in as warnings; this happens in + # this test, so l1 reports the error as a warning! + l1 = node_factory.get_node(start=False, allow_warning=True) # Insist on upfront script we're not going to match. l1.daemon.env["DEV_OPENINGD_UPFRONT_SHUTDOWN_SCRIPT"] = "76a91404b61f7dc1ea0dc99424464cc4064dc564d91e8988ac" l1.start() diff --git a/tests/test_connection.py b/tests/test_connection.py index d04fddde1..88a57fa35 100644 --- a/tests/test_connection.py +++ b/tests/test_connection.py @@ -1956,8 +1956,10 @@ def test_update_fee(node_factory, bitcoind): @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") def test_fee_limits(node_factory, bitcoind): - l1, l2, l3, l4 = node_factory.get_nodes(4, opts=[{'dev-max-fee-multiplier': 5, 'may_reconnect': True}, - {'dev-max-fee-multiplier': 5, 'may_reconnect': True}, + l1, l2, l3, l4 = node_factory.get_nodes(4, opts=[{'dev-max-fee-multiplier': 5, 'may_reconnect': True, + 'allow_warning': True}, + {'dev-max-fee-multiplier': 5, 'may_reconnect': True, + 'allow_warning': True}, {'ignore-fee-limits': True, 'may_reconnect': True}, {}]) diff --git a/tests/test_misc.py b/tests/test_misc.py index f9e634f29..1c35ff829 100644 --- a/tests/test_misc.py +++ b/tests/test_misc.py @@ -1336,7 +1336,7 @@ def test_bitcoind_goes_backwards(node_factory, bitcoind): @flaky def test_reserve_enforcement(node_factory, executor): """Channeld should disallow you spending into your reserve""" - l1, l2 = node_factory.line_graph(2, opts={'may_reconnect': True}) + l1, l2 = node_factory.line_graph(2, opts={'may_reconnect': True, 'allow_warning': True}) # Pay 1000 satoshi to l2. l1.pay(l2, 1000000) diff --git a/tests/test_pay.py b/tests/test_pay.py index 9f15a0db4..0a2c36da4 100644 --- a/tests/test_pay.py +++ b/tests/test_pay.py @@ -234,7 +234,8 @@ def test_pay0(node_factory): def test_pay_disconnect(node_factory, bitcoind): """If the remote node has disconnected, we fail payment, but can try again when it reconnects""" l1, l2 = node_factory.line_graph(2, opts={'dev-max-fee-multiplier': 5, - 'may_reconnect': True}) + 'may_reconnect': True, + 'allow_warning': True}) # Dummy payment to kick off update_fee messages l1.pay(l2, 1000) @@ -261,7 +262,7 @@ def test_pay_disconnect(node_factory, bitcoind): l1.set_feerates((10**6, 1000**6, 1000**6, 1000**6), False) # Wait for l1 notice - l1.daemon.wait_for_log(r'Peer transient failure in CHANNELD_NORMAL: channeld: .*: update_fee \d+ outside range 1875-75000') + l1.daemon.wait_for_log(r'Peer transient failure in CHANNELD_NORMAL: channeld WARNING: .*: update_fee \d+ outside range 1875-75000') # Make l2 fail hard. l2.rpc.close(l1.info['id'], unilateraltimeout=1) diff --git a/tests/test_plugin.py b/tests/test_plugin.py index 7483fa638..e0e9d86d8 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -398,11 +398,16 @@ def test_plugin_connected_hook_chaining(node_factory): l1 is configured to accept connections from l2, but not from l3. we check that logger_a is always called and logger_b only for l2. """ - opts = [{'plugin': [ - os.path.join(os.getcwd(), 'tests/plugins/peer_connected_logger_a.py'), - os.path.join(os.getcwd(), 'tests/plugins/reject.py'), - os.path.join(os.getcwd(), 'tests/plugins/peer_connected_logger_b.py'), - ]}, {}, {}] + opts = [{'plugin': + [os.path.join(os.getcwd(), + 'tests/plugins/peer_connected_logger_a.py'), + os.path.join(os.getcwd(), + 'tests/plugins/reject.py'), + os.path.join(os.getcwd(), + 'tests/plugins/peer_connected_logger_b.py')], + 'allow_warning': True}, + {}, + {'allow_warning': True}] l1, l2, l3 = node_factory.get_nodes(3, opts=opts) l2id = l2.info['id'] @@ -822,7 +827,10 @@ def test_channel_state_changed_unilateral(node_factory, bitcoind): The misc_notifications.py plugin logs `channel_state_changed` events. """ - opts = {"plugin": os.path.join(os.getcwd(), "tests/plugins/misc_notifications.py")} + # FIXME: We can get warnings from unilteral changes, since we treat + # such errors a soft because LND. + opts = {"plugin": os.path.join(os.getcwd(), "tests/plugins/misc_notifications.py"), + "allow_warning": True} l1, l2 = node_factory.line_graph(2, opts=opts) l1_id = l1.rpc.getinfo()["id"]