GH-3399: wait on the fact the test asserts, not on a count of envelopes

[jeremydmiller]

Test-only. No product change.

Symptom

CoreTests.Bugs.Bug_3399_batched_message_separated_handler_codegen.batched_handler_actually_executes failed in full-suite runs — 2/3, and 3/3 in some configurations — while passing 5/5 in isolation. That combination is why CI stayed green.

Nothing was broken

Probed at the moment the tracked session completes, then polled: immediate=0 eventual=1. The batched handler runs; the test was reading its static counter too early. Generated code for all four Bug_3399 chains is byte-identical across the builds involved.

The wait was counting the wrong thing

WaitForExecutionOf<T>(count) counts envelopes of a type, deduped by envelope id. Under MultipleHandlerBehavior.Separated a single batch produces three ItemDeleted3399[] envelopes, not two — the batch lands on its own execution queue and is then relayed to each sticky handler queue. Measured from session.AllRecordsInOrder():

ExecutionFinished env=...5310 dest=local://coretests.bugs.itemdeleted3399/          <- relay source
ExecutionFinished env=...b332 dest=local://coretests.bugs.otherdeletedhandler3399/  <- sibling chain
Received          env=...a676 dest=local://coretests.bugs.telemetryhandler3399/     <- never executed

The first two satisfy a count of 2 between them, so the session was released while the handler the assertion depends on had only been received.

The fix

Stop counting. Gate on the observable being asserted, via an ITrackedCondition on TelemetryHandler3399.Batched > 0.

This is the second time this test has been fixed by tightening its wait, and the second time the wait still did not name what it asserts — GH-4167 replaced WaitForMessageToBeReceivedAt (released at receipt) with the execution count. A count of executions cannot express "TelemetryHandler3399 ran", so the test no longer tries to express it that way. The comment now records the measured envelope trace so the next person doesn't have to rediscover it.

Why it surfaced now

JasperFx 2.57.1 shifted timing, exactly as #714 did for GH-4167. Both times a JasperFx change stopped masking this race rather than causing it — see the Block AllowSynchronousContinuations history on GH-4167, where this same test was one of three that surfaced.

Confirmed by holding the JasperFx pin as the only variable, three full runs per configuration:

Wolverine	JasperFx	result
pre-#4178	2.57.0	3/3 pass
pre-#4178	2.57.1	2/3 fail
#4178	2.57.1	3/3 fail

JasperFx 2.57.1 and Wolverine 6.30.3 are both clean. An initial bisect that varied the priming change and the JasperFx pin together pointed at #4178; isolating the pin corrected that.

Verification

Full CoreTests 3/3 green at 2666 (previously 0/3 or 1/3), Wolverine.Http.Tests 997. Three runs rather than one, because a ⅔ failure rate is precisely what a single green run fails to detect.

🤖 Generated with Claude Code