Repository navigation
Windows reflection test session hangs until timeout without writing a TRX report #7554
Description
Summary
The Windows engine test job can time out after ten minutes while running passing tests in reflection mode. The test application then produces no TRX report, so ExpectedStateTests.Pass fails even though none of the completed tests failed. This prevents otherwise valid pull requests from passing CI.
Reproduction
Observed on head 0fa9dcf617ec59dd13ea5201e152c53cc02efd9e in Windows engine job 126346401450.
Run the Windows engine CI job, which invokes the test application with --treenode-filter /**[EngineTest=Pass] --timeout 10m --reflection.
The log reports InstanceMethodDataSource_DoesNotReuseEnumerationInstance and Run still active at eight minutes. The session times out at ten minutes with 6719 succeeded, 26 skipped, and zero failed tests. The parent engine assertion reports that the TRX file was not written. The log does not identify the class for Run, and a reliable minimal reproduction is not yet established.
Expected and actual
Expected: all passing tests complete and write their report. Actual: two tests remain active until the session timeout; the enclosing engine test fails because the report is missing. Investigate the reflection-mode hang rather than increasing the timeout.
Environment
GitHub Actions windows-latest, .NET 10, Release/net10.0, reflection mode. Found while maintaining #7538; its diagnostic-ID changes do not alter execution. The fresh-base run on #7538 head 7255a02734204c00ac515094b5c12975babbd8c5 passed its Windows engine job (126385788305). This confirms intermittency, not a diagnosed fix; keep this issue open.
Acceptance criteria
- Identify the fully qualified tests and the wait or execution path responsible for the reflection session stalling; use hang diagnostics to distinguish a test-body hang from discovery, hooks, or scheduling.
- Fix the underlying cause without raising the session timeout or skipping the affected tests.
- Add focused regression coverage for the diagnosed cause and validate the full Windows engine session in CI.
Triage at main 4891fce71adee5d0d66e19c9fc20a367b9cca1e9: InstanceMethodDataSource_DoesNotReuseEnumerationInstance is in tests/TUnit.TestProject/Bugs/6361/Tests.cs, class Issue6361InstanceMethodDataSourceIsolationTests. The other active Run test remains unidentified.
Activity
thomhurst commentedon Nov 4, 2026
Investigation and diagnostic change pushed in #7565 at
10541d08d69533a28940f510574ecc0af099ec66.The two active names are deferred containers:
TUnit.TestProject.Bugs._7106.DeferredClassDataSourceReceiver<T>.RunandTUnit.TestProject.Bugs._6361.Issue6361InstanceMethodDataSourceIsolationTests.InstanceMethodDataSource_DoesNotReuseEnumerationInstance.TestSessionCoordinator.ExpandDeferredPlaceholdersAsyncreports them running before scheduling, andReportDeferredPlaceholderResultsAsynccompletes them after the scheduler returns. Their being active does not locate a hung test body. The archived Windows diagnostic artifact contains no managed stacks. Inspection did not establish a lost wake-up in the dynamic channel or a root cause elsewhere.The full filtered pass suite on macOS completed in 1m49s without hanging; an unrelated ordering-sensitive assertion failed and is tracked as #7564. Release/net10.0 engine project build passed with zero warnings/errors; a focused 6361 reflection smoke run using the hang-dump arguments passed four nodes. No engine-suite tests were run locally.
The existing outer engine hang detector waits thirty minutes, but this child exits at ten minutes. #7565 enables an eight-minute hang dump only for the Windows reflection pass child, retaining the ten-minute timeout and all tests. The existing workflow uploads
**/hangdump*.Waiting for AOT workflow run 41784848139, dispatched on the PR head. On completion, inspect the Windows engine job and any
HangDump-engine-tests-windows-latestartifact. If it captures a recurrence, inspect async wait chains to distinguish scheduler bookkeeping from session hooks/static disposal, implement the diagnosed fix and focused regression, and then revalidate Windows. A passing run alone is not evidence of a fix; keep this issue open. Draft #7565 also has its requested Codex review pending.Bound reflection hang dump by an absolute deadline (#7554)
Capture Windows reflection child hangs before session timeout (#7554)
Bound reflection hang dump by an absolute deadline (#7554)
+semver:minor - Capture the stalled Windows reflection test process b…
thomhurst commentedon Nov 4, 2026
The hang recurred on main
885ee5f799in AOT run 41835902493, Windows engine job 126594604554. The eight-minute deadline capturedhangdump.windows-reflection-pass.dmpin artifactHangDump-engine-tests-windows-latest(artifact ID 13326712580, 95,927,730 compressed bytes). The long-lived names are again the deferred containers; several other rows were active for 0–1 seconds at capture, so the names alone still do not establish a deadlock.Local
dotnet-dump10.0.750501 cannot analyze this Windows dump on macOS (explicit unsupported-platform error). Draft #7584, head16207232aa2af6d60d849b979538e1834b26b36c, adds optional Windows-hosted stack extraction. actionlint 1.7.7 and git diff --check passed. No engine tests were run locally.Waiting for analysis run 41843170874. When it finishes, download
Windows-engine-dump-analysis, inspectmanaged-stacks.txt(clrthreads, clrstack -all, dumpasync -stacks), identify the underlying wait, and implement a focused fix/regression. Normal engine/AOT tests also run; this diagnostic path cannot make a failed test run look green. #7584 investigates this issue and does not close it. Codex review was requested for its draft head.Fix Windows dump async analysis for #7554
thomhurst commentedon Nov 4, 2026
The earlier #7569 review run 41788317575 passed; its remaining failure is the #7554 Windows reflection-session hang. Current #7584 head is 5d49c63.
Analysis job 126628274163 in run 41845629047 failed downloading artifact 13326712580: download-artifact listed eight artifacts and reported that the exact ID was absent, although the REST artifact list still returns that 95,927,730-byte artifact. No stacks were produced. The unrelated engine/AOT jobs are still running; they cannot repair this completed analysis failure.
Tried another captured dump instead of waiting or rerunning the same failed download: dispatched run https://github.com/thomhurst/TUnit/actions/runs/41846095741 on #7584 with source run 41839749604 and artifact 13329411785 (95,302,052 bytes), captured by the latest failed Windows engine check on #7569. When this run completes, inspect Windows-engine-dump-analysis/managed-stacks.txt, diagnose the wait and implement focused regression coverage. If download fails again, inspect its job log and replace the artifact download route rather than repeating it. No engine tests ran locally. No on-hold label was added for this workflow wait.
Select a specific diagnostic artifact for #7554
Fix exact dump artifact download for #7554
thomhurst commentedon Nov 4, 2026
The earlier run 41846095741 failed, but the replacement analysis job in run 41847961912 succeeded. Its Windows-engine-dump-analysis artifact contains 1,508 lines of clrthreads, clrstack and dumpasync output, with usable managed frames and no download failure. The diagnostic capability now works; no further artifact-download workaround is needed.
Current-head Claude and Codex reviews are positive and the sole inline finding was fixed and resolved. Marked #7584 ready at unchanged head b4dc614. Promotion started Claude review run 41849691624; read that verdict before arming auto-merge. CI is also starting. This is a workflow wait, with no on-hold label.
The captured process has several threads in Thread.StartInternal called by DedicatedThreadExecutor.ExecuteAsync during after-test hooks, with long inline engine continuation chains. dumpasync also shows two HookGeneratorTest.AfterEachTest Task.Delay waits, plus deferred scheduling bookkeeping. These are evidence to investigate for #7554, not yet proof of a root cause; do not claim that this diagnostic PR fixes the hang or closes #7554. Next investigate dedicated-thread creation/resource pressure and identify the outstanding task from the dump before changing execution code. No engine tests ran locally.
Capture native thread waits to investigate #7554
10 remaining items
thomhurst commentedon Nov 4, 2026
Reopened: the Windows reflection passing-suite failure recurred after #7594 merged, on main
e6c7dee4f0db64691a6206435e969464cb244f38in AOT run 41878194086.ExpectedStateTests.Passfailed after 8m11s without a TRX report, following the eight-minute diagnostic dump deadline. The AOT jobs and other engine jobs passed. This was attempt 1; it was not rerun because the cause is not established as infrastructure.The existing reduction of STA repetitions is already present, so closure as fixed is premature. The two long-lived names are still deferred placeholders and do not locate the stall. New dump artifact:
HangDump-engine-tests-windows-latest, ID13347464325, compressed size 95,360,813 bytes.Dispatched analysis run 41888472009 on main with source run
41878194086and exact artifact13347464325. This is a diagnostic dispatch, not an unchanged-run retry. When it completes, inspectWindows-engine-dump-analysis(managed stacks, native stacks, thread objects and runtime version), compare process progress and CPU use with the earlier diagnosis in #7594, and implement a fix supported by this new capture. Do not raise the timeout or skip tests. No engine tests ran locally. No on-hold label was added for this workflow wait.thomhurst commentedon Nov 4, 2026
Inspected the completed analysis job in run 41888472009 rather than waiting for the unrelated engine/AOT jobs. The fresh dump after #7594 still has eight callers in ThreadNative_Start. Five target state words are 0x9420 (the disassembly checks bit 10, which is set); three targets are already executing/ending with state 0x0202b020. Native threads 36–38 are in Windows loader initialization: thread 36 waits in KERNELBASE!GetConsoleLangId / KernelBaseDllInitialize / LdrpInitializeThread, and 37–38 wait in LdrpDrainWorkQueue during LdrpInitializeThread. Three already-exited CrossPlatformTestExecutor threads also wait in LdrpDrainWorkQueue during LdrShutdownThread. This identifies a Windows loader/console wait as another path to investigate, rather than assuming more STA repetitions need removing. SOS reports 100% CPU and eight running pool workers, but one dump does not establish progress over time or the loader wait owner.
Do not rely on the diagnostic's hard-coded native Thread +0x110 field as an OS thread ID: those values disagree with clrthreads for the same target addresses in this capture. The captured native/managed stacks remain usable. No engine tests ran locally and no undiagnosed rerun was requested. The source capture and analysis remain in hosted artifacts. Next isolate console/loader involvement with a minimal Windows thread-start reproduction or capture loader-lock ownership and per-thread CPU time before changing executor semantics. #7583 also has deterministic STAThreadTests snapshot failures introduced by #7594; those can be repaired independently while this investigation continues.
Refresh STA fixture snapshots after repeat reduction (#7554)
thomhurst commentedon Nov 4, 2026
The earlier wait for #7584 run 41860407100 is obsolete: that run completed and #7584 merged. #7583 head 37414b1 still fails its Windows reflection session in run 41889307483; the STA snapshots now pass. Moved from the PR lock to this issue lock rather than deferring again.
Rechecked the fresh analysis from 41888472009: thread 36 waits in GetConsoleLangId during DLL initialization; threads 37–38 and three exiting executor threads wait in LdrpDrainWorkQueue. Existing critical-section output only reports 93 scanned entries. This does not prove an executor bug, and #7594 did not deliver this issue's acceptance criteria. No replacement closes #7583 or #7554; no human choice or external release is required. An unchanged test rerun would not establish a fix.
Pushed diagnostic follow-up #7603 at f3b40be: loader-lock ownership, verbose critical sections, module versions and per-thread CPU/elapsed times; removed the inconsistent Thread+0x110 field read. actionlint 1.7.7, PowerShell parsing and diff checks passed. No engine tests ran locally. This investigates rather than closes #7554.
Dispatched https://github.com/thomhurst/TUnit/actions/runs/41894299321 against source run 41878194086, artifact 13347464325. Next inspect native-stacks.txt in Windows-engine-dump-analysis, correlate the loader owner and CPU times with thread stacks, then implement only a diagnosed fix. Thread times may be unavailable if absent from the source dump; remaining output is still retained. #7603 is draft with Codex review requested; keep it draft until current-head Claude and Codex verdicts are positive. No on-hold label or undiagnosed rerun was added.
thomhurst commentedon Nov 4, 2026
The obsolete wait for #7584 run 41869617159 is cleared: that run succeeded and #7584 merged. Followed #7569's recurring Windows engine failure to #7554 and #7603 under their own locks.
Inspected the completed analysis job from run 41894299321. Both PEB LoaderLock and !critsec resolve successfully: loader lock 00007ff856fe9810 is owned by OS thread 27d4 (debugger thread 36), in NtDeviceIoControlFile / GetConsoleLangId during KernelBaseDllInitialize. Its elapsed lifetime is only 2.376 seconds, with zero recorded user/kernel CPU. Threads 37–38 are 2.331/2.255 seconds old. This snapshot therefore does not establish that the loader wait lasted eight minutes. The busiest recorded thread has only 5.625 seconds user CPU; the previous SOS 100% CPU reading does not prove sustained spinning. Next compare another temporal capture or isolate Windows console/thread-start interaction before changing executor semantics.
#7603 has positive Claude and Codex verdicts on f3b40be, no review threads, and no blocking findings. The symbol/output checks requested by Claude are satisfied by the artifact. Optional command-array refactoring is unnecessary for this diagnostic change. Marked ready with the head unchanged; read the promotion Claude verdict before arming auto-merge. Run 41894299321 still has engine/AOT jobs in flight; this is a workflow wait, not an on-hold condition.
Resolve routes checked: #7194 remains delivered by #7569 with its Closes link; neither main nor another PR supersedes that deletion. #7554 remains open and unimplemented; #7594 did not eliminate recurrence. No finished-parent, stale criteria, human choice, upstream release or credentials gate applies. No unchanged-head test rerun or speculative executor fix was made. No engine tests ran locally. All acquired locks released at unit end.
thomhurst commentedon Nov 4, 2026
PR #7593 head b4bd5a2 again fails only the Windows reflection pass session (run 41892648253, job 126793832445): eight-minute diagnostic deadline, deferred placeholders still active, child exit -1 without its TRX. Other checks pass. No unchanged-head rerun was requested.
Followed this blocker and diagnostic PR #7603 under their own locks. Read every review surface: current-head Codex and both Claude verdicts are positive, no inline comments or threads, and CodeRabbit/Greptile have no findings. The successful hosted analysis already confirms the symbol output requested by Claude; optional command-array refactoring remains unnecessary. Promotion Claude run 41895688323 passed. Armed and verified squash auto-merge through Enable-AutoMerge.ps1 at unchanged f3b40be.
Waiting for promotion CI run 41895687235 (and .NET run 41895687254). Diagnostic run 41894299321 has passed its Windows engine job, but that intermittent pass does not fix #7554. The existing temporal evidence remains insufficient to blame an eight-minute loader wait: the captured loader owner was only 2.376 seconds old. Next compare another temporal capture or isolate Windows console/thread-start interaction; do not raise timeouts or infer a fix from a passing run. #7593 remains for Renovate to merge after the underlying failure is fixed. No local engine tests ran and no on-hold label was added.
Remove accidental snapshot BOMs for #7554
thomhurst commentedon Nov 4, 2026
Main AOT run 41895377139 at 5cb7601 failed only Engine tests (windows-latest). All three AOT jobs and the Ubuntu/macOS engine jobs passed. ExpectedStateTests.Pass failed after the eight-minute dump deadline without a TRX; Run and InstanceMethodDataSource_DoesNotReuseEnumerationInstance remained active. This matches #7554, not a demonstrated infrastructure failure, so no unchanged-run rerun was requested.
Dispatched diagnostic run 41901280925 on #7603 branch issue-7554-loader-diagnostics to analyze this newer capture: source run 41895377139, exact HangDump-engine-tests-windows-latest artifact 13355892202. Next inspect Windows-engine-dump-analysis native-stacks.txt and compare loader ownership, thread ages and CPU times against run 41894299321. The previous loader owner was only 2.376 seconds old, so do not infer an eight-minute loader deadlock or change executor behavior without further evidence. This dispatch requests analysis of a new dump; it does not claim a fix or close #7554. No engine tests ran locally. No on-hold label added for this workflow wait.
Capture Windows loader ownership and thread CPU times (#7603)
thomhurst commentedon Nov 4, 2026
Followed the failing Windows engine check from #7599 to this blocker under its own lock. The obsolete wait for Claude run 41893737866 is cleared (success); #7599 now has positive Claude and Codex verdicts on 731e334 and all five review threads resolved. Its Windows reflection pass session failed again in run 41903646332, job 126832373098, without a TRX.
Inspected the completed Windows-engine-dump-analysis artifact from run 41901280925 (source main run 41895377139). Native thread 40 / OS 1328 owns LdrpLoaderLock 00007ffa5ff29810 while waiting in NtDeviceIoControlFile / GetConsoleLangId during KernelBaseDllInitialize. Its elapsed lifetime is 3.945 seconds with zero recorded user/kernel time; three exiting threads wait in LdrpDrainWorkQueue. Seven ThreadNative_Start targets split into three 0x0202b020 and four 0x9420 state words. The largest recorded thread user CPU time is 0.593 seconds. This independently repeats the console/loader stack from the earlier capture, but still does not establish an eight-minute loader wait or sustained CPU spinning. The analysis run's Windows engine job passed; intermittency does not satisfy this issue's acceptance criteria.
Started diagnostic run https://github.com/thomhurst/TUnit/actions/runs/41908125296 on main against #7599's newer failure, source run 41903646332 and exact dump artifact 13358839692. Next inspect its native-stacks.txt, managed-stacks.txt and thread-objects.txt to compare loader ownership, thread ages and startup waits with both previous captures. If the same short-lived loader pattern repeats, obtain temporal capture or a minimal console/thread-start reproduction before altering executor behavior. This is analysis of a new capture, not an unchanged-head test rerun; no timeout or test exclusions changed. No local Engine.Tests ran.
Resolve routes checked: #7603 merged diagnostic tooling, not a fix for #7554. Neither current main nor a replacement delivers #7554's acceptance criteria; #7599 remains the implementation of #7596 with its Closes link. Parent closure, supersession, stale acceptance criteria, a human choice, upstream release and credentials gates do not apply. Work has progressed to the new diagnostic run rather than deferring the same completed run again. No on-hold label added.
thomhurst commentedon Nov 4, 2026
The original wait for run 41784848139 is obsolete (completed successfully). Rechecked the issue, native dependencies/sub-issues, open PRs, all issue-7554 branches and worktrees: prior branches contain merged diagnostic/repetition changes, with no unpublished full fix. Removed the stale claim and re-claimed under the driver-owned issue lock.
Inspected the completed analysis job of run 41908125296. It repeats the short-lived loader pattern: owner OS 32f4 / debugger thread 39 is 5.191 seconds old, with newly started tests near capture. That cannot demonstrate an eight-minute loader deadlock. The parent runner launches up to four child engine sessions per CPU; the full pass child includes thousands of dedicated-thread hooks. Instead of another unchanged wait or speculative shipped-executor change, opened draft #7606 at 4393488 to isolate ExpectedStateTests.Pass from sibling engine child processes with global NotInParallel. It preserves every child test, internal parallelism, timeout and hang diagnostics.
Release/net10.0 engine-project build passed (281 existing warnings, zero errors); diff checks passed. The analyzer warnings remain tracked in #7410. No Engine.Tests ran locally. Full AOT workflow dispatched on the PR branch: https://github.com/thomhurst/TUnit/actions/runs/41908929688 . This validates the contention fix against the normal Windows engine workload; inspect its Windows result and capture before claiming the hypothesis is confirmed. If it still fails, isolation is insufficient and the fresh evidence needs further diagnosis. Claude review starts automatically and Codex review was requested for this draft head.
Resolve routes checked: neither main nor a replacement implements the full issue; no native parent/child closure or open prerequisite applies. No human choice, upstream release, credentials or external lock prevents the scheduling change. No timeout increase, test exclusion, undiagnosed rerun or on-hold label was used. This unit published a candidate fix rather than deferring behind the completed run. Keep #7554 open pending hosted validation and review.
Isolate the full passing engine session from sibling children (#7554) (…