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"
-  PYTEST_OPTS_BASE: "--reruns=10 -vvv --junit-xml=report.xml --timeout=1800 --durations=10"
+  PYTEST_OPTS_BASE: "-vvv --junit-xml=report.xml --timeout=1800 --durations=10"
 
 jobs:
   prebuild:
@@ -337,7 +337,7 @@ jobs:
     timeout-minutes: 120
     env:
       RUST_PROFILE: release # Has to match the one in the compile step
-      PYTEST_OPTS: --reruns=10 -vvv --junit-xml=report.xml --timeout=1800 --durations=10
+      PYTEST_OPTS: -vvv --junit-xml=report.xml --timeout=1800 --durations=10
     needs:
       - compile
     strategy:
@@ -453,7 +453,7 @@ jobs:
     env:
       RUST_PROFILE: release # Has to match the one in the compile step
       CFG: compile-gcc
-      PYTEST_OPTS: --reruns=10 -vvv --junit-xml=report.xml --timeout=1800 --durations=10 --test-group-random-seed=42
+      PYTEST_OPTS: -vvv --junit-xml=report.xml --timeout=1800 --durations=10 --test-group-random-seed=42
     needs:
       - compile
     strategy:
@@ -541,7 +541,7 @@ jobs:
       RUST_PROFILE: release
       SLOW_MACHINE: 1
       TEST_DEBUG: 1
-      PYTEST_OPTS: --reruns=10 -vvv --junit-xml=report.xml --timeout=1800 --durations=10 --test-group-random-seed=42 
+      PYTEST_OPTS: -vvv --junit-xml=report.xml --timeout=1800 --durations=10 --test-group-random-seed=42 
     needs:
       - compile
     strategy:
@@ -553,7 +553,7 @@ jobs:
             PYTEST_OPTS: --test-group=1  --test-group-count=12
           - NAME: ASan/UBSan (02/12)
             GROUP: 2
-            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)
             GROUP: 3
             PYTEST_OPTS: --test-group=3  --test-group-count=12
@@ -632,7 +632,7 @@ jobs:
     env:
       VALGRIND: 0
       GENERATE_EXAMPLES: 1
-      PYTEST_OPTS: --reruns=10 -vvv --junit-xml=report.xml --timeout=1800 --durations=10
+      PYTEST_OPTS: -vvv --junit-xml=report.xml --timeout=1800 --durations=10
       TEST_NETWORK: regtest
     needs:
       - compile
@@ -678,7 +678,7 @@ jobs:
     timeout-minutes: 120
     env:
       RUST_PROFILE: release # Has to match the one in the compile step
-      PYTEST_OPTS: --reruns=10 -vvv --junit-xml=report.xml --timeout=1800 --durations=10
+      PYTEST_OPTS: -vvv --junit-xml=report.xml --timeout=1800 --durations=10
     needs:
       - compile
     strategy:

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

@@ -1332,7 +1332,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);
@@ -1341,14 +1340,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));
+		}
 	}
 }
 

lightningd/subd.c

@@ -438,6 +438,8 @@ static bool handle_peer_error(struct subd *sd, const u8 *msg, int fds[1])
 
 	/* Don't free sd; we may be about to free channel. */
 	sd->channel = NULL;
+	/* While it's cleaning up, this is not a leak! */
+	notleak(sd);
 	sd->errcb(channel, peer_fd, desc, err_for_them, disconnect, warning);
 	return true;
 }
@@ -641,6 +643,8 @@ static void destroy_subd(struct subd *sd)
 
 		/* Clear any transient messages in billboard */
 		sd->billboardcb(channel, false, NULL);
+		/* While it's cleaning up, this is not a leak! */
+		notleak(sd);
 		sd->channel = NULL;
 
 		/* We can be freed both inside msg handling, or spontaneously. */
@@ -928,11 +932,6 @@ void subd_release_channel(struct subd *owner, const void *channel)
 		assert(owner->channel == channel);
 		owner->channel = NULL;
 		tal_free(owner);
-	} else {
-		/* Caller has reassigned channel->owner, so there's no pointer
-		 * to this subd owner while it's freeing itself.  If we
-		 * ask memleak right now, it will complain! */
-		notleak(owner);
 	}
 }
 

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])