Skip to content

test(ci): stop FakeOtlpCollectorTests from hanging the integration leg - #1084

Merged
mforce merged 1 commit into
mainfrom
fix/1082-otlp-collector-hang
Oct 5, 2026
Merged

mforce merged 1 commit into
mainfrom
fix/1082-otlp-collector-hang

Conversation

@mforce

@mforce mforce commented Oct 5, 2026

Copy link
Copy Markdown
Owner

Closes #1082

Root cause

The hang is a race inside .NET 10's managed HttpListener, and the collector waited on it without a bound.

  • Dump (run 37256150116): the test thread is blocked in FakeOtlpCollector.Dispose() on _serveTask.GetAwaiter().GetResult(). No thread is running listener or socket code, so ServeAsync was parked on an await that never completed.
  • Library source (HttpListener.Managed.cs, release/10.0): Dispose() holds _internalLock, drains _asyncWaitQueue in Cleanup, and sets _state = Closed only in its finally. BeginGetContext does not take _internalLock. It checks _state == Started and appends to _asyncWaitQueue. An accept issued between the drain and _state = Closed is therefore never completed.
  • Why this test: Cleanup closes the stalled export's connection. That wakes the serve loop through the absorbing catch and back into GetContextAsync() while the listener still reports IsListening == true, which is the window above.
  • Located, not inferred: an instrumented copy of the collector recorded the serve loop's last await. In all 5 hangs in 6,000 iterations it was parked at GetContextAsync(), with IsListening == true when the accept was issued.

Change map

File Change Why
tests/Cluckwork.Api.IntegrationTests/Infrastructure/FakeOtlpCollector.cs (ServeAsync) The accept is raced against _terminal. If termination wins, the loop returns. Dispose calls Fault before disposing the listener, so the loop stops whether or not the listener ever completes the accept.
same file (Dispose) _serveTask.Wait(10 s), otherwise TimeoutException("…serve loop did not stop within 10 s of disposal") Any other stuck await now fails the test in 10 s with a clear message instead of hitting the 5-minute blame timeout and aborting the leg.

No product code changed. Test count is unchanged: FakeOtlpCollectorTests has 11 tests on base and 11 on head.

Evidence

In-process stress probe. A throwaway console app compiles the real FakeOtlpCollector.cs and repeats the hanging test's sequence: stalled export, AssertNoRequestAsync, close the client, Dispose. A hang is a Dispose() that has not returned after 5 s. Unpinned, on a 12-core host:

Collector Iterations Hangs
base (origin/main) 2,000 + 10,000 2 + 17
head 10,000 + 10,000 0 + 0

Pinned to one CPU under three busy loops (the #676 recipe), base gave 0 hangs in 2,000 runs. The race needs two threads running in parallel, so single-CPU pinning hides it.

Real test class loop (dotnet test --filter FakeOtlpCollectorTests, 60 s blame timeout):

Runs Green Not green
base 60 59 1 (output not kept, so the failure mode is not identified)
head 60 60 0

Mutation table. Each row was run, then restored.

Mutation Expected Observed
Probe: head minus the accept race, bound kept Dispose fails fast with the clear message 3 × TimeoutException: …did not stop within 10 s of disposal in 6,000 runs; 0 hangs
Probe: head minus the bound, accept race kept no hangs 0 hangs in 10,000 runs
Named test: base shape + every accept after the first orphaned, IsListening gate removed so the orphan is reached deterministically hangs blame fired at 60 s, test run aborted with a hang dump
Same orphaning, head passes passed
Same orphaning, head minus the accept race (bound kept) fails fast TimeoutException, failed in 10 s
Control: the same orphaning without removing the IsListening gate, base shape (not discriminating) passed. Reaching the orphan then depends on the narrow race, so this mutation alone cannot show the hang. That is why the rows above remove the gate.

Also green at head: OtlpSubprocessExporterTests (11/11), the collector's other caller, and SchemaDocsTests (4/4).

Gaps

  • No deterministic regression test was added. The race lives inside HttpListener with no seam to force it, and a stress test at the measured base rate (about 1 in 600) would not reliably go red. The evidence is the probe and the mutations above.
  • An orphaned accept task is left unobserved after disposal. It never completes, so it cannot raise an unobserved-task exception.

The managed HttpListener drains its accept queue before marking itself
closed, so an accept issued during Dispose is never completed. The serve
loop now races each accept against the collector's termination, and
Dispose bounds its wait for the serve loop.
@mforce

mforce commented Oct 5, 2026

Copy link
Copy Markdown
Owner Author

Review by Codex (gpt-6-astra) at 30a5767

Approve. No P1/P2 or actionable P3 findings.

  • I opened the CI dump with dotnet-dump analyze and ran clrstack -all. Thread 0xdb0 is blocked in FakeOtlpCollector.Dispose, waiting for the serve task from the named stalled-export test. No stack executes HttpListener. There are ordinary test-runner/runtime socket frames, so “no socket code” is too broad. dumpasync could not resolve the required type; the dump alone does not identify the parked await.
  • The dump runtime matches .NET 10.0.12. Its managed listener source confirms the race: cleanup drains pending accepts before disposal sets Closed, while BeginGetContext checks state outside the queue lock and never takes the disposal lock.
  • The actual fix at FakeOtlpCollector.cs:213–215 races the accept against _terminal.Task; it does not merely check a shutdown token. Dispose completes that task first. An accept started across the shutdown boundary can remain incomplete without keeping the serve loop waiting.
  • I forced an orphan in the built head assembly by removing its pending accept from the listener queue. Disposal returned in 13.7 ms, the serve task completed, and a replacement collector bound the same port and returned HTTP 200. This checks the orphan outcome and port reuse independently of the rare scheduling window. Endpoint removal and socket closure also follow the runtime cleanup implementation, preserving the Flaky: FakeOtlpCollector HttpListener disposed / address in use in OtlpSubprocessExporterTests and FakeOtlpCollectorTests #672 fix.
  • At FakeOtlpCollector.cs:295–297, the bound starts after synchronous listener disposal, so it is not a total ten-second disposal deadline. Substituting an unfinished serve task produced the intended TimeoutException after 10.001 s. The remaining continuation needs scheduling, not network progress; I found no evidence of a normal slow-runner false failure. A cleanup exception can mask an assertion already unwinding, but reporting failed teardown is acceptable here compared with aborting the integration leg.

Validation: FakeOtlpCollectorTests 11/11 × 3, OtlpSubprocessExporterTests 11/11 × 3, one class per run, with DOTNET_USE_POLLING_FILE_WATCHER=1 under sg docker. Build passed. No full integration run. The large stress counts and instrumented 5/5 claim remain author-supplied evidence; I did not repeat that probe.

Thermo-nuclear review found no structural regression. The change reuses existing terminal state and standard task primitives. Ponytail review: Lean already. Ship.

@mforce
mforce merged commit 623111c into main Oct 5, 2026
16 checks passed
@mforce
mforce deleted the fix/1082-otlp-collector-hang branch October 5, 2026 08:10
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

test(ci): FakeOtlpCollectorTests can hang and abort the integration leg

1 participant