feat(ci): Capture diagnostics when runtime tests stall - #24007
feat(ci): Capture diagnostics when runtime tests stall#24007MartinZikmund wants to merge 1 commit into
Conversation
macOS and Linux desktop Skia runtime tests freeze mid-test and are killed by the 60-minute job timeout, leaving no evidence of what blocked. Adds two complementary instruments: - TestRunStallMonitor: an in-process heartbeat on a dedicated thread that separately probes the UI dispatcher and the thread pool each tick. A dedicated thread is used so pool starvation cannot silence it, which is what separates "UI thread blocked" from "pool starved" from "process frozen" (no heartbeat line at all). Enabled on CI, opt-in locally via UNO_TEST_STALL_MONITOR_INTERVAL_SECONDS. - stall-watchdog.sh: watches the console log and, once it goes quiet, captures managed stacks (dotnet-stack), native stacks (sample on macOS, eu-stack and /proc on Linux) and process state, re-arming for each subsequent stall. Optionally terminates the app before the job wall so results and the failed-test list are still written. The macOS driver no longer aborts on a non-zero app exit, so the failed-test list is written and a retry can run only the failures instead of the whole suite. closes #24006 refs #24005, #23967 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01RgHbZ4EHYrK6uTkPTtKbq8
|
Claude finished @MartinZikmund's task in 5m 32s —— View job PR Review —
|
| # | Severity | Line | Summary |
|---|---|---|---|
| 1 | Minor | L158–168 | ManualResetEventSlim in ProbeThreadPool() is never disposed — leaks a kernel wait handle per tick and leaves a latent ObjectDisposedException risk in the thread-pool callback on the timeout path. Can be disposed on the success and queue-failed paths; timeout path must stay unmanaged. |
| 2 | Minor | L203–207 | _disposed guard in Dispose() is not volatile / not atomic — two concurrent callers can both pass the check, leading to double-Cancel + double-Dispose() on the CancellationTokenSource. Use Interlocked.CompareExchange on an int flag. |
| 3 | Minor | L212 | _thread.Join(2 s) is shorter than ProbeTimeout (5 s), so _cts.Dispose() can be called while the background thread is mid-probe. The practical race is near-zero (cancelled token short-circuits before the next WaitHandle access), but the join should cover the maximum blocking time. |
Nit — shell scripts
| # | Severity | Location | Summary |
|---|---|---|---|
| 4 | Nit | stall-watchdog.sh L138 |
Hard-timeout capture bypasses MAX_CAPTURES, so total captures can reach MAX_CAPTURES + 1. Intentional, but a one-line comment prevents future confusion. |
| 5 | Nit | macos-skia-runtime-tests.sh L41 |
APP_EXIT is captured and echoed but not acted on — add a comment confirming it's informational only, to avoid a "forgotten check" read-later. |
Cross-cutting notes
#nullable enableis correctly present at the top of the newTestRunStallMonitor.cs. TheUnitTestsControl.csfield_stallMonitoris declared without?(nullable-oblivious context, no#nullable enablein that file) — consistent with the pre-existing style of that file.- The
Interlocked.Exchange(ref _stallMonitor, null)?.Dispose()pattern inUnitTestsControl.csis correct and ensures only one caller reachesDispose()from the outside; the fix in finding Paths are either not shown or shown not as in the UWP Designer #2 adds the same safety inside the class. - No
event Action/event Action<T>— not applicable here. - No allocations in hot paths beyond what the diagnostic intent requires.
- Conventional Commits format (
feat(ci):) is correct. - The two Linux stages sharing a single template with
testResultLabel-suffixed artifact names is noted correctly in the PR description.
There was a problem hiding this comment.
Pull request overview
This PR improves diagnosability of Desktop Skia runtime-test stalls on macOS and Linux by adding (1) an in-process heartbeat during test execution and (2) an out-of-process watchdog that captures stacks and publishes them as CI artifacts, even on failure/timeouts.
Changes:
- Add
TestRunStallMonitorheartbeat logging during runtime test execution (CI-enabled by default). - Add
stall-watchdog.shand wire it into macOS/Linux runtime-test drivers to capture diagnostics when console output stalls, plus a hard-timeout termination path. - Publish new “stall diagnostics” artifacts from macOS/Linux CI jobs using
condition: always().
Review summary (verdict + counts):
- Verdict: requires changes
- Issues found: 2 bugs, 1 performance
Reviewed changes
Copilot reviewed 7 out of 7 changed files in this pull request and generated 2 comments.
Show a summary per file
| File | Description |
|---|---|
| src/SamplesApp/SamplesApp.UnitTests.Shared/Controls/UnitTest/UnitTestsControl.cs | Starts/stops the stall monitor and updates current test name during execution. |
| src/SamplesApp/SamplesApp.UnitTests.Shared/Controls/UnitTest/TestRunStallMonitor.cs | New heartbeat monitor that probes dispatcher + thread pool and logs periodic status. |
| build/test-scripts/stall-watchdog.sh | New out-of-process watchdog that detects log silence and captures managed/native diagnostics. |
| build/test-scripts/macos-skia-runtime-tests.sh | Runs watchdog alongside tests, tees console log, and preserves post-run failed-test list generation. |
| build/test-scripts/linux-skia-runtime-tests.sh | Runs watchdog alongside tests, tees console log (both Xvfb and non-Xvfb paths). |
| build/ci/tests/.azure-devops-tests-macos-skia.yml | Publishes macOS stall diagnostics artifact unconditionally. |
| build/ci/tests/.azure-devops-tests-linux-skia.yml | Publishes Linux stall diagnostics artifact unconditionally (with result-label suffix). |
Suppressed comments (1)
build/test-scripts/stall-watchdog.sh:85
- The Darwin capture path also relies on
timeout, which may be unavailable on the macOS hosted image. Iftimeoutis missing, bothsampleandvmmapcaptures can be skipped entirely, which defeats the purpose of macOS diagnostics.
Darwin)
# Native stacks for every thread, including AppKit/CoreAnimation frames that
# managed stacks cannot show. This is the artefact for a host-level livelock.
timeout 120 sample "$pid" 10 -f "$dir/sample.txt" >/dev/null 2>&1 \
|| log "sample failed"
timeout 60 vmmap --summary "$pid" > "$dir/vmmap.txt" 2>&1 || true
;;
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| var sw = Stopwatch.StartNew(); | ||
| var signal = new ManualResetEventSlim(false); | ||
|
|
||
| if (!ThreadPool.UnsafeQueueUserWorkItem(_ => signal.Set(), null)) | ||
| { | ||
| return "queue-failed"; | ||
| } | ||
|
|
||
| return signal.Wait(ProbeTimeout) | ||
| ? $"{sw.ElapsedMilliseconds}ms" | ||
| : $"STARVED(>{ProbeTimeout.TotalSeconds:F0}s)"; |
| # Managed stacks — the primary artefact for a managed deadlock or a hung await. | ||
| if command -v dotnet-stack >/dev/null 2>&1; then | ||
| timeout 120 dotnet-stack report --process-id "$pid" > "$dir/dotnet-stack.txt" 2>&1 \ | ||
| || log "dotnet-stack failed (see $dir/dotnet-stack.txt)" | ||
| fi |
| return signal.Wait(ProbeTimeout) | ||
| ? $"{sw.ElapsedMilliseconds}ms" | ||
| : $"STARVED(>{ProbeTimeout.TotalSeconds:F0}s)"; | ||
| } |
There was a problem hiding this comment.
ManualResetEventSlim implements IDisposable and should be disposed to release the underlying kernel wait handle. As written, the handle is leaked on every probe tick.
The tricky case is the timeout path: the thread-pool work item still holds a reference to signal and will call signal.Set() after this method returns — so you cannot Dispose() it there without risking ObjectDisposedException. A clean solution is to avoid the disposable altogether on that path:
| } | |
| private static string ProbeThreadPool() | |
| { | |
| var sw = Stopwatch.StartNew(); | |
| var signal = new ManualResetEventSlim(false); | |
| if (!ThreadPool.UnsafeQueueUserWorkItem(_ => signal.Set(), null)) | |
| { | |
| signal.Dispose(); | |
| return "queue-failed"; | |
| } | |
| if (!signal.Wait(ProbeTimeout)) | |
| { | |
| // Cannot dispose here: the work item may still call Set() on signal. | |
| // Let the GC collect it once the work item completes and releases its ref. | |
| return $"STARVED(>{ProbeTimeout.TotalSeconds:F0}s)"; | |
| } | |
| signal.Dispose(); // safe: work item already ran and released signal | |
| return $"{sw.ElapsedMilliseconds}ms"; | |
| } |
(Alternatively, use a SemaphoreSlim(0,1) which documents the one-shot intent more clearly.)
| if (_disposed) | ||
| { | ||
| return; | ||
| } |
There was a problem hiding this comment.
_disposed is a plain bool field but Dispose() reads and writes it from whichever thread calls it with no synchronization. Two concurrent callers could both pass the if (_disposed) guard, leading to double-Cancel + double-Dispose on the CancellationTokenSource (the second Dispose() throws ObjectDisposedException).
Because the caller already uses Interlocked.Exchange to null-out _stallMonitor before calling Dispose(), a second concurrent caller is unlikely in practice — but the guard inside Dispose() should still be correct in isolation. Mark _disposed as volatile, or use Interlocked.CompareExchange:
| } | |
| public void Dispose() | |
| { | |
| if (Interlocked.CompareExchange(ref _disposedFlag, 1, 0) != 0) | |
| { | |
| return; | |
| } | |
| _cts.Cancel(); | |
| _thread.Join(TimeSpan.FromSeconds(2)); | |
| _cts.Dispose(); | |
| Console.WriteLine($"{LogPrefix} stopped after {Format(_runElapsed.Elapsed)}"); | |
| } |
(and change the field declaration to private int _disposedFlag;)
|
|
||
| _disposed = true; | ||
| _cts.Cancel(); | ||
| _thread.Join(TimeSpan.FromSeconds(2)); |
There was a problem hiding this comment.
The join timeout is 2 s, but ProbeDispatcher() can block in task.Wait(ProbeTimeout) for up to ProbeTimeout = 5 s. If the background thread is mid-probe when Dispose() is called, the join will time out, and _cts.Dispose() will be called while the thread is still running. On the next loop iteration the thread checks !_cts.IsCancellationRequested (which reads the already-cancelled flag — safe) before accessing _cts.Token.WaitHandle, so the practical risk is near-zero, but the join should match or exceed the maximum blocking time:
| _thread.Join(TimeSpan.FromSeconds(2)); | |
| _thread.Join(TimeSpan.FromSeconds(10)); // covers ProbeTimeout (5 s) plus headroom |
|
|
||
| if [ "$HARD_TIMEOUT_SECONDS" -gt 0 ] && [ "$ELAPSED" -ge "$HARD_TIMEOUT_SECONDS" ]; then | ||
| log "hard timeout reached after ${ELAPSED}s — capturing then terminating pid $PID" | ||
| CAPTURES=$(( CAPTURES + 1 )) |
There was a problem hiding this comment.
The hard-timeout capture increments CAPTURES and calls capture without checking MAX_CAPTURES, so the actual number of diagnostics directories can reach MAX_CAPTURES + 1 (if a stall capture fires on the same poll as the hard timeout). Intentional given the hard timeout is a one-shot terminal event, but worth a brief comment so a future reader doesn't wonder whether the cap was missed:
| CAPTURES=$(( CAPTURES + 1 )) | |
| # Hard-timeout capture is unconditional (one-shot, terminal) — intentionally bypasses MAX_CAPTURES. | |
| CAPTURES=$(( CAPTURES + 1 )) | |
| capture "hard timeout after ${ELAPSED}s" "$CAPTURES" "$PID" |
| set -e | ||
|
|
||
| kill $WATCHDOG_PID 2>/dev/null || true | ||
| echo "Runtime tests app exited with code $APP_EXIT" |
There was a problem hiding this comment.
APP_EXIT is captured but only echoed — it isn't passed to fail-empty or used to fail the build differently. That's fine (the test-results XML drives the verdict), but worth calling out in a comment so a future maintainer doesn't wonder whether the check was accidentally dropped:
| echo "Runtime tests app exited with code $APP_EXIT" | |
| ## The app exit code must not abort the script: the failed-test list below is what lets a | |
| ## pipeline retry run only the failures instead of the whole suite. | |
| set +e | |
| dotnet SamplesApp.Skia.Generic.dll --runtime-tests=$TEST_RESULTS_FILE 2>&1 | tee "$APP_LOG" | |
| APP_EXIT=${PIPESTATUS[0]} | |
| set -e | |
| ## APP_EXIT is informational only — the build verdict comes from the results XML below. |
|
🤖 Your WebAssembly Skia Sample App stage site is ready! Visit it here: https://unowasmprstaging.z20.web.core.windows.net/pr-24007/wasm-skia-net9/index.html |
| private static string ProbeThreadPool() | ||
| { | ||
| var sw = Stopwatch.StartNew(); | ||
| var signal = new ManualResetEventSlim(false); |
| catch (Exception e) | ||
| { | ||
| // The monitor must never be able to fail a run it is only observing. | ||
| Console.WriteLine($"{LogPrefix} probe error: {e.GetType().Name}: {e.Message}"); | ||
| } |
| catch (Exception e) | ||
| { | ||
| return $"error({e.GetType().Name})"; | ||
| } |
| catch (Exception) | ||
| { | ||
| return "?"; | ||
| } |
|
|
When_Reorder_DragDrop_ScrollsAwayFromDraggedItem_KeepsExtentAndPositions fails intermittently on the iOS Skia CI leg, always on the mid-drag extent assertion and always with the same values: ExtentHeight 1560 instead of 1440, exactly 3 phantom 40px rows. Observed on master build 225991 (attempt 1, passed on retry), PR #24007 build 226424, and PR #24012 build 226524 where 5/5 stage attempts failed on this single test across different hosted agents. The identical values every failure point at a timing-dependent residue of the extent estimation fixed by #23946 surfacing on the iOS simulator profile — tracked in #24013. Desktop and Android Skia legs keep running the test, so the regression coverage #23946 added stays in place. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NsWEWZN3E2AtwQm7UU1cFm
When_Reorder_DragDrop_ScrollsAwayFromDraggedItem_KeepsExtentAndPositions fails intermittently on the iOS Skia CI leg, always on the mid-drag extent assertion and always with the same values: ExtentHeight 1560 instead of 1440, exactly 3 phantom 40px rows. Observed on master build 225991 (attempt 1, passed on retry), PR #24007 build 226424, and PR #24012 build 226524 where 5/5 stage attempts failed on this single test across different hosted agents. The identical values every failure point at a timing-dependent residue of the extent estimation fixed by #23946 surfacing on the iOS simulator profile — tracked in #24013. Desktop and Android Skia legs keep running the test, so the regression coverage #23946 added stays in place. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NsWEWZN3E2AtwQm7UU1cFm (cherry picked from commit c0ce315) # Conflicts: # src/Uno.UI.RuntimeTests/Tests/Windows_UI_Xaml_Controls/Given_ListViewBase.cs
There was a problem hiding this comment.
i think a more effective method would be enforce a per-test hard timeout, like 1min, on the engine level
for heavy tests, we can adjust case-by-case with [TimeoutAttribute]
(which you have mentioned in an issue for uno7)
GitHub Issue: closes #24006
Related: #24005 (macOS host freeze), #23967 (
When_MsAppDataLinux hang) — this PR does not fix either, it makes them diagnosable.PR Type:
🏗️ Build or CI related changes
What changed? 🚀
macOS and Linux desktop Skia runtime tests freeze mid-test and get killed by the 60-minute job timeout, leaving no evidence of what blocked. The log just stops. There is no stack, no dump, and no way to tell whether the UI thread, the thread pool, or the whole process stopped.
This adds two complementary instruments. They answer different halves of the question, which is why both are here.
1.
TestRunStallMonitor— in-process heartbeatsrc/SamplesApp/SamplesApp.UnitTests.Shared/Controls/UnitTest/TestRunStallMonitor.csEmits one line per interval (30 s on CI) while tests run:
The design point is that the three signals are independent, so the shape of the output identifies the culprit:
dispatcher=BLOCKED,threadPoolfinethreadPool=STARVEDinTestclimbingawaitnever completes — a test buggcPauseDeltaThe heartbeat runs on a dedicated thread, not a timer or the thread pool — a pool-starvation hang must still produce output, otherwise it is indistinguishable from a fully frozen process. That distinction is the entire point of the instrument.
Enabled automatically under
IS_CI; locally it is off unless you setUNO_TEST_STALL_MONITOR_INTERVAL_SECONDS.2.
stall-watchdog.sh— out-of-process stack capturebuild/test-scripts/stall-watchdog.sh, wired into the macOS and Linux drivers.Watches the console log. When it goes quiet past a threshold (default 180 s) it captures, while the process is still stuck:
dotnet-stack report— managed stackssample <pid> 10— native stacks for every thread, including AppKit/CoreAnimation frames that managed stacks cannot showeu-stack,/proc/<pid>/status,/wchan, and per-threadstat/wchanpssnapshot, and the log tail so the capture records which test was runningIt re-arms, so a run that stalls three times yields three captures (capped, default 6). Published as a new
runtime-tests-desktop-skia-{macos,linux[-framebuffer]}-diagnosticsartifact viacondition: always()+continueOnError: true.UNO_WATCHDOG_HARD_TIMEOUT_SECONDS(default 3300 s = 55 min, against the 60-minute job wall) captures a final snapshot and thenSIGTERMs the app so the results XML and failed-test list are still written. 55 min was chosen deliberately: the longest observed successful macOS run is ~52 min, so this rescues diagnostics from runs that would have been killed at 60 while leaving every currently-passing run untouched.3. macOS driver no longer aborts on a non-zero app exit
macos-skia-runtime-tests.shran underset -e, so a crash or non-zero exit skippedlist-failedentirely and the retry re-ran the whole ~8.5k-test suite. It now captures the exit code and continues, matching what the Linux driver already does. (fail-emptystill fails the build when no results could be read, so a crash with no results is still red.)Validation ✅
Runtime —
stall-watchdog.shexecuted end-to-end against a simulated stalling process on Ubuntu 24.04 (WSL), driving two distinct stalls plus a hard-timeout case:Compile —
SamplesApp.Skia.csprojbuilds clean (net10.0, 0 errors). Verified the new type is actually in the output rather than silently excluded:TestRunStallMonitor,[stall-monitor],UnoTestStallMonitorandSTARVED(>are all present inSamplesApp.Skia.dll.Not validated at runtime: the in-process heartbeat has not run on a real macOS/Linux CI agent — that only happens once this is merged. It is logging-only and disabled off-CI, so the blast radius is a few extra stdout lines per run.
Notes for reviewers
testResultLabelto avoid a collision. (The pre-existing…-linux-failuresartifact is not suffixed and so does collide between those two stages — flagging it, not fixing it here.)pgrepand astatper 15 s.PR Checklist ✅
Screenshots Compare Test Runresults.