Skip to content

Fix Layer1ScaleTest flake: concurrent per-association Simulator delivery#80

Merged
ptesavol merged 1 commit into
mainfrom
claude/fix-layer1scale-flake
Jul 11, 2026
Merged

Fix Layer1ScaleTest flake: concurrent per-association Simulator delivery#80
ptesavol merged 1 commit into
mainfrom
claude/fix-layer1scale-flake

Conversation

@ptesavol

Copy link
Copy Markdown
Collaborator

Fix Layer1ScaleTest flake: deliver Simulator operations concurrently per association

Three mechanisms, each established from runtime evidence (instrumented failing runs / a crash-report stack): (1) the Simulator's single dispatcher thread was the whole simulated network's serialization point, so under load every RPC timeout fired spuriously and the DHT's timeout-pruning gutted live neighbor tables; (2) once (1) was fixed and the test ran 2× faster, a latent test-side race surfaced — two reads of the same live ConnectionsView asserted as equal (atomic in single-threaded TS, racy in C++); (3) the higher lookup rate also surfaced a latent null-dereference in RoutingSession: consecutive RoutingTablesCache lookups can straddle the cache's 15s TTL boundary, so a get() microseconds after a successful has()/get() returns null (value_or(nullptr)), and the session dereferenced it.

Symptom

Layer1ScaleTest.SingleLayer1Dht failed in ~1/3 of isolated local runs (pre-existing at main dd99e2c6, documented as a known follow-up in PR #77; CI hides it via --repeat until-pass:2):

Expected: (layer1Node->getNeighborCount()) >= (numberOfNodesPerKBucketDefault / 2), actual: 2 vs 4

Baseline measured on this branch's parent (55fa6d9): 5 failures / 15 isolated runs.

Root cause (established with runtime instrumentation, per the runtime-evidence-debugging methodology)

The Simulator's single dispatcher thread executed every delivered operation's entire downstream processing inline (protobuf parse → ConnectionManager → RPC dispatch → response resolution). Under the 49-node layer-1 join wave (~59k deliveries, amplified by routing: H6: hop-sends total=27500), the dispatcher became the whole network's serialization point:

  • H5b: sim-queue ... avgDelayMs=8179 ... qsize=6190 — the mean time a message spent waiting in the dispatcher queue was 8–14 seconds; the queue was ~6,000 operations deep.
  • Every timeout in the system then fired spuriously: the 2s routing hop-ack timeout (RouterRpcRemote routingTimeout{2000}) failed on virtually every layer-1 message (H3: routing-failure ... svc=layer1 × 16,445 in one run; H5c counted 25,218 RPC responses arriving after their request had already timed out vs 3,859 on time), and the 10s request timeout killed discovery fetches (H3: fetch-fail ... err=RPC_TIMEOUT × 484) and layer-1 pings (96% failure: H2: ping-result svc=layer1 ok=0 × 527 vs ok=1 × 23).
  • The DHT then pruned live neighbors exactly as the TS reference logic prescribes for dead ones. The victim trace (node d03957f0, one instrumented run) shows the k-bucket growing to 15 and then being batch-pruned — three H2: removeContact lines at a time with no preceding ping-result, at an exact 10-second cadence (13:50:59, :51:09, :51:19, :51:29, :51:39, :51:49 — DiscoverySession::onRequestFailed after each 10s getClosestPeers timeout, parallelism 3), including six removals in 2 ms dropping the bucket 7→2:
13:51:48.996 H2: removeContact svc=layer1 node=d03957f0 contact=d3feeda5
13:51:48.997 H2: removeContact svc=layer1 node=d03957f0 contact=edb37110
13:51:48.997 H2: removeContact svc=layer1 node=d03957f0 contact=e872c3f2
13:51:48.998 H2: removeContact svc=layer1 node=d03957f0 contact=d23062ab
13:51:48.998 H2: removeContact svc=layer1 node=d03957f0 contact=d7fd53b6
13:51:48.998 H2: removeContact svc=layer1 node=d03957f0 contact=cb6be21c   → count=2

The final neighbor count is a sample of this churn at the instant the join wave returns; its tail dipped below 4 in ~1/3 of runs (even passing runs had minima of 4–5).

TS does not hit this because its deliveries run on the single V8 event loop where the per-operation cost is far lower; nothing in the protocol depends on cross-association ordering (the real transports — websocket, WebRTC datachannel — only guarantee per-connection FIFO).

Fix

Simulator now hands each dequeued operation to a per-association SharedSerialExecutor (worker pool): per-association FIFO is preserved (the dispatcher is the only poster and pops in deadline order), while different associations deliver concurrently. stop() drains the in-flight handoffs so no call-out races teardown. The dispatcher thread is back to doing only what it is for: sequencing latency deadlines.

Second mechanism: a latent test-side race, exposed by the ~2× speedup

With deliveries no longer glacial, the fixed test reaches its assertions in ~107s (was ~205s) — while trailing background pings are still opening layer-0 connections. One clean-build run then failed a different assertion:

Layer1ScaleTest.cpp:123: Expected equality ... getConnectionCount(): 25 vs 27

layer1Node->getConnectionsView() and layer0Node->getConnectionsView() are the same object by construction (the layer-1 node is built with the layer-0 node's view — test utils, matching TS). TS evaluates the count/list equalities atomically on its single thread, so they are tautologies there; the mechanical C++ port reads the live view twice and races the churn (the two values differing by 2 on one object is the proof). The port-faithful fix asserts the identity that makes the TS equalities true — EXPECT_EQ(layer1Node->getConnectionsView(), layer0Node->getConnectionsView()) — in both Layer1ScaleTest cases, keeping the meaningful assertions (node id, neighbor count) unchanged. All baseline failures (7 assertion hits across 5 failing runs) were the neighbor-count line; this race never fired at baseline speed.

Evidence the mechanism is gone (same instrumentation, after the fix)

Metric before after
sim-queue mean delay / worst depth 8,179 ms / 6,190 ops 3 ms / 6 ops
discovery session timeouts per run 28–40 0
discovery fetch failures per run 645–791 0–2
layer-1 ping failure rate 96% 5%
late RPC responses 25,218 vs 3,859 on-time 628 vs 14,075
min layer-1 neighbor count across 48 nodes 4–5 (threshold: 4) 15–16

Third mechanism: latent RoutingTablesCache TTL null-dereference (SIGSEGV)

One clean-build run crashed with SIGSEGV (rc=139). The macOS crash report pinned it (thread StreamrBackground, KERN_INVALID_ADDRESS at 0x340):

SortedContactList<RoutingRemoteContact>::getClosestContacts(...)   ← null `this`
RoutingSession::updateAndGetRoutablePeers()
Router::doRouteMessage(...)
Router::send(...) lambda  [routing serial executor]

RoutingSession::updateAndGetRoutablePeers() made three consecutive cache lookups — has(), get()->getSize(), get() — and every lookup re-evaluates the entry's 15s TTL (RoutingTablesCache::get returns value_or(nullptr)). When the entry's age crossed the TTL boundary between lookups, the later get() expired it and returned null, and the session dereferenced the null table. This is a pre-existing latent bug (the TS original has the same has-then-get shape but effectively never hits the window); the post-fix test performs far more routing lookups per second, which surfaced it. Fixed by fetching the cached table once and rebuilding when it is null or empty.

Verification

All runs are isolated single processes on the same machine (arm64 mac, Debug build), no concurrent test binaries.

  • Baseline (parent commit 55fa6d9): 10 PASS / 5 FAIL of 15 runs — all failures at the neighbor-count assertion, e.g. actual: 2 vs 4.
  • Instrumented build + Simulator fix, same repetition count: 15 PASS / 0 FAIL, per-run mechanism logs clean (0 session timeouts vs 28-40 before; dispatcher queue depth ≤ 15 vs 6,190; min layer-1 neighbors 15-16 vs 4-5).
  • Final clean build (instrumentation removed, all three fixes): 20 PASS / 0 FAIL of 20 runs, plus 14 more green runs during interim batches.
  • Suites (local, serial): unit 181/181, integration 43/43 (includes both Layer1Scale tests and the 200-node correctness test), end-to-end 7/7 (×3 consecutive full-suite runs).
  • packages/streamr-dht/lint.sh rc=0; full-tree cmake --build build clean.

Known pre-existing e2e flake (not addressed here): one full-suite e2e run crashed in the websocket connection layer (WebsocketClientConnector::connect map insertion racing teardown/concurrent sends on StreamrWorker1). A crash report from the same morning — hours before this branch existed — shows the same suite SEGV-ing in Layer0Test::TearDown → DhtNode::stop → EventEmitter lock, so this family predates this change; it is connection-layer locking territory (phase A0) and is left as a follow-up. Crash reports: ~/Library/Logs/DiagnosticReports/streamr-dht-test-end-to-end-2026-07-11-{072147,163308}.ips.

🤖 Generated with Claude Code

Three evidence-backed fixes (baseline: 5/15 isolated runs failed the
neighbor-count assertion; after: 20/20 pass):

1. Simulator: the single dispatcher thread executed every delivered
   operation's entire downstream processing inline, becoming the whole
   simulated network's serialization point. Under the 49-node layer-1
   join wave (~59k deliveries) its queue backed up ~6,000 deep and
   delivery latency reached 8-14s (measured), blowing every RPC timeout
   so discovery/ping timeout-pruning removed live neighbors as fast as
   they were found. Deliveries now run on a per-association serial view
   of the shared worker pool: per-association FIFO is preserved (the
   guarantee real transports give), associations deliver concurrently,
   and stop() drains in-flight handoffs.

2. RoutingSession: consecutive RoutingTablesCache lookups (has, get for
   getSize, get) each re-evaluate the 15s TTL, so a later lookup could
   expire the entry and return null (value_or(nullptr)) microseconds
   after an earlier one succeeded; the null table was then dereferenced
   (SIGSEGV in getClosestContacts, seen in a crash report). Fetch once
   and rebuild when null or empty.

3. Layer1ScaleTest: the connection-count/list equality assertions read
   the SAME live ConnectionsView twice; single-threaded TS evaluates
   them atomically (tautology) but in C++ background connection churn
   mutates the view between reads (observed 25 vs 27). Assert the view
   identity that makes the TS equalities true.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant