Flaky fixes

.github/workflows/ci.yaml

@@ -16,7 +16,7 @@ env:
   RUST_PROFILE: release
   SLOW_MACHINE: 1
   CI_SERVER_URL: "http://35.239.136.52:3170"
-  GLOBAL_PYTEST_OPTS: "--reruns=10 -vvv"
+  GLOBAL_PYTEST_OPTS: "-vvv"
 
 jobs:
   prebuild:
@@ -431,7 +431,7 @@ jobs:
     env:
       RUST_PROFILE: release # Has to match the one in the compile step
       CFG: compile-gcc
-      PYTEST_OPTS: --test-group-random-seed=42 --timeout=1800 --durations=10 --reruns=10
+      PYTEST_OPTS: --test-group-random-seed=42 --timeout=1800 --durations=10
     needs:
       - compile
     strategy:
@@ -502,7 +502,7 @@ jobs:
       RUST_PROFILE: release
       SLOW_MACHINE: 1
       TEST_DEBUG: 1
-      PYTEST_OPTS: --test-group-random-seed=42 --timeout=1800 --durations=10 --reruns=10
+      PYTEST_OPTS: --test-group-random-seed=42 --timeout=1800 --durations=10
     needs:
       - compile
     strategy:
@@ -512,7 +512,7 @@ jobs:
           - NAME: ASan/UBSan (01/12)
             PYTEST_OPTS: --test-group=1  --test-group-count=12
           - NAME: ASan/UBSan (02/12)
-            PYTEST_OPTS: --test-group=2  --test-group-count=12 -n 1
+            PYTEST_OPTS: --test-group=2  --test-group-count=12
           - NAME: ASan/UBSan (03/12)
             PYTEST_OPTS: --test-group=3  --test-group-count=12
           - NAME: ASan/UBSan (04/12)

contrib/pyln-testing/pyln/testing/fixtures.py

@@ -498,7 +498,7 @@ def map_node_error(nodes, f, msg):
 
     map_node_error(nf.nodes, printValgrindErrors, "reported valgrind errors")
     map_node_error(nf.nodes, printCrashLog, "had crash.log files")
-    map_node_error(nf.nodes, checkBroken, "had BROKEN messages")
+    map_node_error(nf.nodes, checkBroken, "had BROKEN or That's weird 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, checkPluginJSON, "had malformed hooks/notifications")

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

@@ -841,7 +841,7 @@ def call(self, method, payload=None, cmdprefix=None, filter=None):
 
 
 class LightningNode(object):
-    def __init__(self, node_id, lightning_dir, bitcoind, executor, valgrind, may_fail=False,
+    def __init__(self, node_id, lightning_dir, bitcoind, executor, may_fail=False,
                  may_reconnect=False,
                  broken_log=None,
                  allow_warning=False,
@@ -900,7 +900,7 @@ def __init__(self, node_id, lightning_dir, bitcoind, executor, valgrind, may_fai
             self.daemon.opts["dev-debugger"] = dbgvar
         if os.getenv("DEBUG_LIGHTNINGD"):
             self.daemon.opts["dev-debug-self"] = None
-        if valgrind:
+        if VALGRIND:
             self.daemon.env["LIGHTNINGD_DEV_NO_BACKTRACE"] = "1"
             self.daemon.opts["dev-no-plugin-checksum"] = None
         else:
@@ -926,7 +926,7 @@ def __init__(self, node_id, lightning_dir, bitcoind, executor, valgrind, may_fai
         dsn = db.get_dsn()
         if dsn is not None:
             self.daemon.opts['wallet'] = dsn
-        if valgrind:
+        if VALGRIND:
             trace_skip_pattern = '*python*,*bitcoin-cli*,*elements-cli*,*cln-grpc*,*clnrest*,*wss-proxy*,*cln-bip353*,*reckless'
             if not valgrind_plugins:
                 trace_skip_pattern += ',*plugins*'
@@ -1653,10 +1653,6 @@ class NodeFactory(object):
     """
     def __init__(self, request, testname, bitcoind, executor, directory,
                  db_provider, node_cls, jsonschemas):
-        if request.node.get_closest_marker("slow_test") and SLOW_MACHINE:
-            self.valgrind = False
-        else:
-            self.valgrind = VALGRIND
         self.testname = testname
 
         # Set test name in environment for coverage file organization
@@ -1755,7 +1751,7 @@ def get_node(self, node_id=None, options=None, dbfile=None,
         db = self.db_provider.get_db(os.path.join(lightning_dir, TEST_NETWORK), self.testname, node_id)
         db.provider = self.db_provider
         node = self.node_cls(
-            node_id, lightning_dir, self.bitcoind, self.executor, self.valgrind, db=db,
+            node_id, lightning_dir, self.bitcoind, self.executor, db=db,
             port=port, grpc_port=grpc_port, options=options, may_fail=may_fail or expect_fail,
             jsonschemas=self.jsonschemas,
             **kwargs
@@ -1872,7 +1868,7 @@ def killall(self, expected_successes):
             # leak detection upsets VALGRIND by reading uninitialized mem,
             # and valgrind adds extra fds.
             # If it's dead, we'll catch it below.
-            if not self.valgrind:
+            if not VALGRIND:
                 try:
                     # This also puts leaks in log.
                     leaks = self.nodes[i].rpc.dev_memleak()['leaks']

gossipd/gossmap_manage.c

@@ -1317,7 +1317,6 @@ void gossmap_manage_channel_spent(struct gossmap_manage *gm,
 				  struct short_channel_id scid)
 {
 	struct gossmap_chan *chan;
-	const struct gossmap_node *me;
 	const u8 *msg;
 	struct chan_dying cd;
 	struct gossmap *gossmap = gossmap_manage_get_gossmap(gm);
@@ -1326,14 +1325,6 @@ void gossmap_manage_channel_spent(struct gossmap_manage *gm,
 	if (!chan)
 		return;
 
-	me = gossmap_find_node(gossmap, &gm->daemon->id);
-	/* We delete our own channels immediately, since we have local knowledge */
-	if (gossmap_nth_node(gossmap, chan, 0) == me
-	    || gossmap_nth_node(gossmap, chan, 1) == me) {
-		kill_spent_channel(gm, gossmap, scid);
-		return;
-	}
-
 	/* Is it already dying?  It's lightningd re-telling us */
 	if (channel_already_dying(gm->dying_channels, scid))
 		return;

hsmd/libhsmd.c

@@ -1820,6 +1820,13 @@ static u8 *handle_sign_anchorspend(struct hsmd_client *c, const u8 *msg_in)
 				    fmt_pubkey(tmpctx, &local_funding_pubkey),
 				    fmt_wally_psbt(tmpctx, psbt));
 	}
+	if (dev_warn_on_overgrind
+	    && psbt->inputs[0].signatures.num_items == 1
+	    && psbt->inputs[0].signatures.items[0].value_len < 71) {
+		hsmd_status_fmt(LOG_BROKEN, NULL,
+				"overgrind: short signature length %zu",
+				psbt->inputs[0].signatures.items[0].value_len);
+	}
 
 	return towire_hsmd_sign_anchorspend_reply(NULL, psbt);
 }

lightningd/connect_control.c

@@ -277,10 +277,22 @@ static void connect_failed(struct lightningd *ld,
 					  connect_nsec,
 					  connect_attempted);
 
-	/* We can have multiple connect commands: fail them all */
-	while ((c = find_connect(ld, id)) != NULL) {
-		/* They delete themselves from list */
-		was_pending(command_fail(c->cmd, errcode, "%s", errmsg));
+	/* There's a race between autoreconnect and connect commands.  This
+	 * matters because the autoreconnect might have failed, but that was before
+	 * the connect_to_peer command gave connectd a new address.  This we wait for
+	 * one we explicitly asked for before failing.
+	 *
+	 * A similar pattern could occur with multiple connect commands, however connectd
+	 * does simply combine those, so we don't get a response per request, and it's a
+	 * very rare corner case (which, unlike the above, doesn't happen in CI!).
+	 */
+	if (strstarts(connect_reason, "connect command")
+	    || errcode == CONNECT_DISCONNECTED_DURING) {
+		/* We can have multiple connect commands: fail them all */
+		while ((c = find_connect(ld, id)) != NULL) {
+			/* They delete themselves from list */
+			was_pending(command_fail(c->cmd, errcode, "%s", errmsg));
+		}
 	}
 }
 

plugins/askrene/askrene.c

@@ -573,6 +573,7 @@ static struct command_result *do_getroutes(struct command *cmd,
 	struct route **routes;
 	struct flow **flows;
 	struct json_stream *response;
+	const struct gossmap_node *me;
 
 	/* update the gossmap */
 	if (gossmap_refresh(askrene->gossmap)) {
@@ -593,6 +594,30 @@ static struct command_result *do_getroutes(struct command *cmd,
 	rq->additional_costs = info->additional_costs;
 	rq->maxparts = info->maxparts;
 
+	/* We also eliminate any local channels we *know* are dying.
+	 * Most channels get 12 blocks grace in case it's a splice,
+	 * but if it's us, we know about the splice already. */
+	me = gossmap_find_node(rq->gossmap, &askrene->my_id);
+	if (me) {
+		for (size_t i = 0; i < me->num_chans; i++) {
+			struct short_channel_id_dir scidd;
+			const struct gossmap_chan *c = gossmap_nth_chan(rq->gossmap,
+									me, i, NULL);
+			if (!gossmap_chan_is_dying(rq->gossmap, c))
+				continue;
+
+			scidd.scid = gossmap_chan_scid(rq->gossmap, c);
+			/* Disable both directions */
+			for (scidd.dir = 0; scidd.dir < 2; scidd.dir++) {
+				bool enabled = false;
+				gossmap_local_updatechan(localmods,
+							 &scidd,
+							 &enabled,
+							 NULL, NULL, NULL, NULL, NULL);
+			}
+		}
+	}
+
 	/* apply selected layers to the localmods */
 	apply_layers(askrene, rq, &info->source, info->amount, localmods,
 		     info->layers, info->local_layer);

tests/benchmark.py

@@ -1,7 +1,8 @@
 from concurrent import futures
 from fixtures import *  # noqa: F401,F403
+from pyln.client import RpcError
 from tqdm import tqdm
-from utils import (wait_for, TIMEOUT)
+from utils import (wait_for, TIMEOUT, only_one)
 
 
 import os
@@ -228,3 +229,36 @@ def test_spam_listcommands(node_factory, bitcoind, benchmark):
 
     # This calls "listinvoice" 100,000 times (which doesn't need a transaction commit)
     benchmark(l1.rpc.spamlistcommand, 100_000)
+
+
+def test_payment_speed(node_factory, benchmark):
+    """This makes sure we don't screw up nagle handling.
+
+    Normally:
+    Name (time in ms)           Min       Max      Mean  StdDev    Median     IQR  Outliers     OPS  Rounds  Iterations
+    test_payment_speed      16.3587  40.4925  27.4874  5.5512  27.7885  8.9291       9;0  36.3803      33           1
+
+    Without TCP_NODELAY:
+    Name (time in ms)           Min       Max      Mean  StdDev    Median     IQR  Outliers     OPS  Rounds  Iterations
+    test_payment_speed     153.7132  163.2027  158.6747  3.4059  158.5219  6.3745       3;0  6.3022       9           1
+    """
+    l1 = get_bench_node(node_factory, extra_options={'commit-time': 0})
+    l2 = get_bench_node(node_factory, extra_options={'commit-time': 0})
+
+    node_factory.join_nodes([l1, l2])
+
+    scid = only_one(l1.rpc.listpeerchannels()['channels'])['short_channel_id']
+    routestep = {
+        'amount_msat': 100,
+        'id': l2.info['id'],
+        'delay': 5,
+        'channel': scid
+    }
+
+    def onepay(l1, routestep):
+        phash = random.randbytes(32).hex()
+        l1.rpc.sendpay([routestep], phash)
+        with pytest.raises(RpcError, match="WIRE_INCORRECT_OR_UNKNOWN_PAYMENT_DETAILS"):
+            l1.rpc.waitsendpay(phash)
+
+    benchmark(onepay, l1, routestep)

tests/conftest.py

@@ -1,6 +1,6 @@
 import pytest
 
-from pyln.testing.utils import EXPERIMENTAL_DUAL_FUND
+from pyln.testing.utils import EXPERIMENTAL_DUAL_FUND, VALGRIND, SLOW_MACHINE
 
 
 # This function is based upon the example of how to
@@ -37,3 +37,5 @@ def pytest_runtest_setup(item):
     else:  # If there's no openchannel marker, skip if EXP_DF
         if EXPERIMENTAL_DUAL_FUND:
             pytest.skip('v1-only test, EXPERIMENTAL_DUAL_FUND=1')
+    if "slow_test" in item.keywords and VALGRIND and SLOW_MACHINE:
+        pytest.skip("Skipping slow tests under VALGRIND")

tests/test_askrene.py

@@ -3,14 +3,15 @@
 from pyln.client import RpcError
 from pyln.testing.utils import SLOW_MACHINE
 from utils import (
-    only_one, first_scid, GenChannel, generate_gossip_store,
+    only_one, first_scid, first_scidd, GenChannel, generate_gossip_store,
     sync_blockheight, wait_for, TEST_NETWORK, TIMEOUT, mine_funding_to_announce
 )
 import os
 import pytest
 import subprocess
 import time
 import tempfile
+import unittest
 
 
 def direction(src, dst):
@@ -1915,3 +1916,46 @@ def test_askrene_reserve_clash(node_factory, bitcoind):
                      layers=['layer2'],
                      maxfee_msat=1000,
                      final_cltv=5)
+
+
+@unittest.skipIf(TEST_NETWORK != 'regtest', 'elementsd doesnt yet support PSBT features we need')
+@pytest.mark.openchannel('v1')
+@pytest.mark.openchannel('v2')
+def test_splice_dying_channel(node_factory, bitcoind):
+    """We should NOT try to use the pre-splice channel here"""
+    l1, l2, l3 = node_factory.line_graph(3,
+                                         wait_for_announce=True,
+                                         fundamount=200000,
+                                         opts={'experimental-splicing': None})
+
+    chan_id = l1.get_channel_id(l2)
+    funds_result = l1.rpc.addpsbtoutput(100000)
+    pre_splice_scidd = first_scidd(l1, l2)
+
+    # Pay with fee by subjtracting 5000 from channel balance
+    result = l1.rpc.splice_init(chan_id, -105000, funds_result['psbt'])
+    result = l1.rpc.splice_update(chan_id, result['psbt'])
+    assert(result['commitments_secured'] is False)
+    result = l1.rpc.splice_update(chan_id, result['psbt'])
+    assert(result['commitments_secured'] is True)
+    result = l1.rpc.splice_signed(chan_id, result['psbt'])
+
+    mine_funding_to_announce(bitcoind,
+                             [l1, l2, l3],
+                             num_blocks=6, wait_for_mempool=1)
+
+    wait_for(lambda: only_one(l1.rpc.listpeerchannels()['channels'])['state'] == 'CHANNELD_NORMAL')
+    post_splice_scidd = first_scidd(l1, l2)
+
+    # You will use the new scid
+    route = only_one(l1.rpc.getroutes(l1.info['id'], l2.info['id'], '50000sat', ['auto.localchans'], 100000, 6)['routes'])
+    assert only_one(route['path'])['short_channel_id_dir'] == post_splice_scidd
+
+    # And you will not be able to route 100001 sats:
+    with pytest.raises(RpcError, match="We could not find a usable set of paths"):
+        l1.rpc.getroutes(l1.info['id'], l2.info['id'], '100001sat', ['auto.localchans'], 100000, 6)
+
+    # But l3 would think it can use both, since it doesn't eliminate dying channel!
+    wait_for(lambda: [c['active'] for c in l3.rpc.listchannels()['channels']] == [True] * 6)
+    routes = l3.rpc.getroutes(l1.info['id'], l2.info['id'], '200001sat', [], 100000, 6)['routes']
+    assert set([only_one(r['path'])['short_channel_id_dir'] for r in routes]) == set([pre_splice_scidd, post_splice_scidd])

tests/test_closing.py

@@ -1,7 +1,7 @@
 from fixtures import *  # noqa: F401,F403
 from pyln.client import RpcError, Millisatoshi
 from shutil import copyfile
-from pyln.testing.utils import SLOW_MACHINE
+from pyln.testing.utils import SLOW_MACHINE, VALGRIND
 from utils import (
     only_one, sync_blockheight, wait_for, TIMEOUT,
     account_balance, first_channel_id, closing_fee, TEST_NETWORK,
@@ -1851,8 +1851,8 @@ def test_onchaind_replay(node_factory, bitcoind):
 
     # Wait for nodes to notice the failure, this seach needle is after the
     # DB commit so we're sure the tx entries in onchaindtxs have been added
-    l1.daemon.wait_for_log("Deleting channel .* due to the funding outpoint being spent")
-    l2.daemon.wait_for_log("Deleting channel .* due to the funding outpoint being spent")
+    l1.daemon.wait_for_log("closing soon due to the funding outpoint being spent")
+    l2.daemon.wait_for_log("closing soon due to the funding outpoint being spent")
 
     # We should at least have the init tx now
     assert len(l1.db_query("SELECT * FROM channeltxs;")) > 0
@@ -3232,7 +3232,7 @@ def check_billboard():
 def test_shutdown(node_factory):
     # Fail, in that it will exit before cleanup.
     l1 = node_factory.get_node(may_fail=True)
-    if not node_factory.valgrind:
+    if not VALGRIND:
         leaks = l1.rpc.dev_memleak()['leaks']
         if len(leaks):
             raise Exception("Node {} has memory leaks: {}"
@@ -3437,7 +3437,6 @@ def test_closing_higherfee(node_factory, bitcoind, executor, anchors):
     wait_for(lambda: l2.rpc.listpeerchannels()['channels'][0]['state'] == 'CLOSINGD_COMPLETE')
 
 
-@unittest.skipIf(True, "Test is extremely flaky")
 def test_htlc_rexmit_while_closing(node_factory, executor):
     """Retranmitting an HTLC revocation while shutting down should work"""
     # FIXME: This should be in lnprototest!  UNRELIABLE.

tests/test_coinmoves.py

@@ -681,7 +681,6 @@ def test_coinmoves_unilateral_htlc_before_included(node_factory, bitcoind):
     check_balances(l1, l2, fundchannel['channel_id'], 0)
 
 
-@pytest.mark.flaky(reruns=5)
 @pytest.mark.openchannel('v1')
 @pytest.mark.openchannel('v2')
 @unittest.skipIf(TEST_NETWORK != 'regtest', "Amounts are for regtest.")