diff --git a/common/status_levels.h b/common/status_levels.h index 79f7bc57313a..baa04ebb4720 100644 --- a/common/status_levels.h +++ b/common/status_levels.h @@ -20,6 +20,9 @@ enum log_level { }; #define LOG_LEVEL_MAX LOG_BROKEN +/* Things that can happen in real life, but we don't expect under CI. */ +#define CI_UNEXPECTED "That's weird: " + const char *log_level_name(enum log_level level); bool log_level_parse(const char *levelstr, size_t len, enum log_level *level); diff --git a/connectd/multiplex.c b/connectd/multiplex.c index d7cbf80e2b59..99137a0f5b9a 100644 --- a/connectd/multiplex.c +++ b/connectd/multiplex.c @@ -106,8 +106,7 @@ static void maybe_free_peer(struct peer *peer) * not reading, we have to give up. */ static void close_peer_io_timeout(struct peer *peer) { - /* BROKEN means we'll trigger CI if we see it, though it's possible */ - status_peer_broken(&peer->id, "Peer did not close, forcing close"); + status_peer_unusual(&peer->id, CI_UNEXPECTED "Peer did not close, forcing close"); io_close(peer->to_peer); } @@ -1083,8 +1082,10 @@ static struct io_plan *write_to_peer(struct io_conn *peer_conn, /* Still nothing to send? */ if (!msg) { /* Draining? We're done when subds are done. */ - if (peer->draining && tal_count(peer->subds) == 0) + if (peer->draining && tal_count(peer->subds) == 0) { + io_wake(&peer->peer_in); return io_sock_shutdown(peer_conn); + } /* If they want us to send gossip, do so now. */ if (!peer->draining) diff --git a/contrib/pyln-testing/pyln/testing/fixtures.py b/contrib/pyln-testing/pyln/testing/fixtures.py index 215c54022325..4bd062ccc327 100644 --- a/contrib/pyln-testing/pyln/testing/fixtures.py +++ b/contrib/pyln-testing/pyln/testing/fixtures.py @@ -609,7 +609,7 @@ def checkBadGossip(node): def checkBroken(node): node.daemon.logs_catchup() - broken_lines = [l for l in node.daemon.logs if '**BROKEN**' in l] + broken_lines = [l for l in node.daemon.logs if '**BROKEN**' in l or "That's weird: " in l] if node.broken_log: ex = re.compile(node.broken_log) broken_lines = [l for l in broken_lines if not ex.search(l)] diff --git a/plugins/xpay/xpay.c b/plugins/xpay/xpay.c index 16717ce3d045..4528a9e2d6b7 100644 --- a/plugins/xpay/xpay.c +++ b/plugins/xpay/xpay.c @@ -38,6 +38,8 @@ struct xpay { bool take_over_pay; /* Are we to wait for all parts to complete before returning? */ bool slow_mode; + /* Suppress calls to askrene-age */ + bool dev_no_age; }; static struct xpay *xpay_of(struct plugin *plugin) @@ -2098,6 +2100,10 @@ static struct command_result *age_layer(struct command *timer_cmd, void *unused) static void start_aging_timer(struct plugin *plugin) { + struct xpay *xpay = xpay_of(plugin); + + if (xpay->dev_no_age) + return; notleak(global_timer(plugin, time_from_sec(60), age_layer, NULL)); } @@ -2422,6 +2428,7 @@ int main(int argc, char *argv[]) xpay = tal(NULL, struct xpay); xpay->take_over_pay = false; xpay->slow_mode = false; + xpay->dev_no_age = false; plugin_main(argv, init, take(xpay), PLUGIN_RESTARTABLE, true, NULL, commands, ARRAY_SIZE(commands), @@ -2434,5 +2441,8 @@ int main(int argc, char *argv[]) plugin_option_dynamic("xpay-slow-mode", "bool", "Wait until all parts have completed before returning success or failure", bool_option, bool_jsonfmt, &xpay->slow_mode), + plugin_option_dev("dev-xpay-no-age", "flag", + "Don't call askrene-age", + flag_option, flag_jsonfmt, &xpay->dev_no_age), NULL); } diff --git a/tests/test_bookkeeper.py b/tests/test_bookkeeper.py index edb57c0aa04f..1b4d086f9aec 100644 --- a/tests/test_bookkeeper.py +++ b/tests/test_bookkeeper.py @@ -318,8 +318,14 @@ def test_bookkeeping_missed_chans_leases(node_factory, bitcoind): l1.wait_local_channel_active(scid) channel_id = first_channel_id(l1, l2) + # Sigh. bookkeeper sorts events by timestamp. If the invoice event happens + # too close, it can change the order, so sleep here. + time.sleep(2) + + # Send l2 funds via the channel l1.pay(l2, invoice_msat) - l1.daemon.wait_for_log(r'coin movement:.*\'invoice\'') + # Make sure they're completely settled, so accounting correct. + wait_for(lambda: only_one(l1.rpc.listpeerchannels()['channels'])['htlcs'] == []) # Now turn the bookkeeper on and restart l1.stop() diff --git a/tests/test_coinmoves.py b/tests/test_coinmoves.py index 0cdefe83fc73..bf5407fd6685 100644 --- a/tests/test_coinmoves.py +++ b/tests/test_coinmoves.py @@ -1221,6 +1221,11 @@ def test_coinmoves_unilateral_htlc_fulfill(node_factory, bitcoind): line = l1.daemon.is_in_log('Tracking output.*/OUR_HTLC') htlc = int(re.search(r'output [0-9a-f]{64}:([0-9]):', line).group(1)) + # commitment tx weight can vary (DER sigs, FML) and so even though the feerate target + # is fixed, the amount of the child tx we create will vary, hence the change varies. + # So it's usually 15579000, but one in 128 it will be 15586000... + anchor_change_msats = bitcoind.rpc.gettxout(anchor_spend_txid, 0)['value'] * 100_000_000_000 + expected_chain1 += [{'account_id': 'wallet', # Anchor spend from fundchannel change 'blockheight': 104, 'credit_msat': 0, @@ -1232,10 +1237,10 @@ def test_coinmoves_unilateral_htlc_fulfill(node_factory, bitcoind): 'utxo': f"{fundchannel['txid']}:{fundchannel['outnum'] ^ 1}"}, {'account_id': 'wallet', # Change from anchor spend 'blockheight': 104, - 'credit_msat': 15579000, + 'credit_msat': anchor_change_msats, 'debit_msat': 0, 'extra_tags': [], - 'output_msat': 15579000, + 'output_msat': anchor_change_msats, 'primary_tag': 'deposit', 'utxo': f"{anchor_spend_txid}:0"}, {'account_id': fundchannel['channel_id'], diff --git a/tests/test_plugin.py b/tests/test_plugin.py index b01005479322..9f1bed283ff2 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -4045,19 +4045,29 @@ def test_sql(node_factory, bitcoind): wait_for(lambda: l3.rpc.sql("SELECT * FROM nodes WHERE alias = '{}'".format(alias))['rows'] != []) # Test json functions - l1.fundchannel(l2) - bitcoind.generate_block(6) - l1.rpc.pay(l2.rpc.invoice(amount_msat=1000000, label='inv1000', description='description 1000 msat')['bolt11']) - ret = l1.rpc.sql("SELECT json_object('peer_id', hex(pc.peer_id), 'alias', alias, 'htlcs'," + scidl1l3, _ = l1.fundchannel(l3) + l1.rpc.pay(l3.rpc.invoice(amount_msat=1000000, label='inv1000', description='description 1000 msat')['bolt11']) + + # Two channels, l1->l3 *may* have an HTLC in flight. + ret = l1.rpc.sql("SELECT json_object('peer_id', hex(pc.peer_id), 'alias', alias, 'scid', short_channel_id, 'htlcs'," " (SELECT json_group_array(json_object('id', hex(id), 'amount_msat', amount_msat))" " FROM peerchannels_htlcs ph WHERE ph.row = pc.rowid)) FROM peerchannels pc JOIN nodes n" " ON pc.peer_id = n.nodeid ORDER BY n.alias, pc.peer_id;") assert len(ret['rows']) == 2 - row1 = json.loads(ret['rows'][0][0]) - row2 = json.loads(ret['rows'][1][0]) - assert row1['peer_id'] == format(l2.info['id'].upper()) - assert len(row2['htlcs']) == 1 - assert row2['htlcs'][0]['amount_msat'] == 1000000 + row1 = json.loads(only_one(ret['rows'][0])) + row2 = json.loads(only_one(ret['rows'][1])) + assert row1 in ({"peer_id": format(l3.info['id'].upper()), + "alias": l3.rpc.getinfo()['alias'], + "scid": scidl1l3, + "htlcs": []}, + {"peer_id": format(l3.info['id'].upper()), + "alias": l3.rpc.getinfo()['alias'], + "scid": scidl1l3, + "htlcs": [{"id": "30", "amount_msat": 1000000}]}) + assert row2 == {"peer_id": format(l2.info['id'].upper()), + "alias": l2.rpc.getinfo()['alias'], + "scid": scid, + "htlcs": []} def test_sql_deprecated(node_factory, bitcoind): diff --git a/tests/test_reckless.py b/tests/test_reckless.py index 64efa6ab6418..10ade3624795 100644 --- a/tests/test_reckless.py +++ b/tests/test_reckless.py @@ -2,7 +2,7 @@ import subprocess from pathlib import PosixPath, Path import socket -from pyln.testing.utils import VALGRIND +from pyln.testing.utils import VALGRIND, SLOW_MACHINE import pytest import os import re @@ -351,6 +351,7 @@ def test_tag_install(node_factory): header = line +@unittest.skipIf(VALGRIND and SLOW_MACHINE, "node too slow for starting plugin under valgrind") def test_reckless_uv_install(node_factory): node = get_reckless_node(node_factory) node.start() diff --git a/tests/test_xpay.py b/tests/test_xpay.py index ca464c801578..5a822bfbdc15 100644 --- a/tests/test_xpay.py +++ b/tests/test_xpay.py @@ -227,14 +227,21 @@ def test_xpay_fake_channeld(node_factory, bitcoind, chainparams, slow_mode): # l2 will warn l1 about its invalid gossip: ignore. # We throttle l1's gossip to avoid massive log spam. + # Suppress debug and below because logs are huge l1, l2 = node_factory.line_graph(2, # This is in sats, so 1000x amount we send. fundamount=AMOUNT, opts=[{'gossip_store_file': outfile.name, 'subdaemon': 'channeld:../tests/plugins/channeld_fakenet', 'allow_warning': True, - 'dev-throttle-gossip': None}, - {'allow_bad_gossip': True}]) + 'dev-throttle-gossip': None, + 'log-level': 'info', + # xpay gets upset if it's aging when we remove cln-askrene! + 'dev-xpay-no-age': None, + }, + {'allow_bad_gossip': True, + 'log-level': 'info', + }]) # l1 needs to know l2's shaseed for the channel so it can make revocations hsmfile = os.path.join(l2.daemon.lightning_dir, TEST_NETWORK, "hsm_secret")