[DO-NOT-MERGE] Diagnostic: JS-progress watchdog for UnitTests hangs

[bghgary]

Status: DO-NOT-MERGE — diagnostic only

[Created by Copilot on behalf of @bghgary]

Verdict

Heartbeat-fed watchdog confirms: slow progress on Ubuntu llvmpipe JSC, not a deadlock.

Run 25026066984: 27✅ 1❌. The lone ❌ is Ubuntu_GCC_JSC failing at Playground rendering with a pixel-diff (First pixel off at 108872 ... Pixel difference: 17308 pixels) — a pre-existing render flake, aborted the job before UnitTests ran. Unrelated to the watchdog.

Ubuntu_Clang_JSC (the previously-failing job) passed JavaScript.All in 141.5 s with 3 PASSED, 4 SKIPPED (ExternalTexture). No watchdog abort. WSL local run: 209 s with [watchdog-heartbeat] pump_frames=... lines visible between mocha output gaps.

Why the previous "60 → 600 s default" wasn't enough

The earlier run on this branch hit a 600-s console-output gap in Materials/Empty-ShaderMaterial and dumped a core. Post-mortem showed gtest in wait_for(16ms), all bgfx threads idle, JS thread blocked in IncrementPendingFrameScopes, DeviceImpl{m_frameBlocked=true, m_pendingFrameScopes=0, m_rendering=false, m_firstFrameStarted=true} — the same quiescent inter-frame snapshot you'd see in either slow-progress or deadlock.

A single core dump can't distinguish the two: the gtest pump loop spends almost all its wall time in wait_for(16ms), so any random-time capture lands there in either case. We needed a tiebreaker — does the render thread actually keep ticking?

Mechanism (this PR)

Two-source watchdog:

1. Console output activity (mocha lines on stdout). Existing channel.
2. Render-thread frame progress. g_pumpFrameCount (atomic), incremented after each Start/Finish cycle in the gtest pump loop.

Watchdog thread polls the atomic every 1 s. When it advances, the "last activity" timestamp resets — so a slow-but-progressing test never trips. Every 30 s, the watchdog emits [watchdog-heartbeat] pump_frames=N so we can see progress in the log even during shader-compile silence. If both sources stall for the timeout window, abort with a message that names both.

This means a real deadlock — render thread stuck in bgfx::frame() or FinishRenderingCurrentFrame() — would now trip cleanly, and slow Materials shader compiles do not.

Default restored to 60 s since false positives are eliminated.

Where it changes

• Apps/UnitTests/Source/Tests.JavaScript.cpp — atomic + watchdog dual-source logic + pump-loop increment.

Follow-ups (other PRs / repos, not this one)

• Slow llvmpipe shader compile chains in Babylon Materials/* are real and consume ~20–30% of the JSC job budget. See [DO-NOT-MERGE] Partner integration test: #1652 + #1646 #1674 for partner-side discussion. Possible mitigations: skip slowest cases on llvmpipe, bump JSC job timeout, or investigate bgfx-side llvmpipe compile cost.

[bghgary]

[Responded by Copilot on behalf of @bghgary]

Correction — earlier root-cause comment was wrong.

The DRI3 / LIBGL_ALWAYS_SOFTWARE hypothesis didn't pan out. After comparing master vs rework-thread-model directly, the regression is branch-specific to anything carrying #1652, not a runner-pool issue:

• Master Linux JSC over the last 12 days: 280–470 s, 0 timeouts across 40 jobs.
• rework-thread-model (bare, no Add synchronous ExternalTexture.CreateForJavaScript and deprecate AddToContextAsync #1646, no watchdog): 5–30+ min, hits 30/60-min timeouts on contended runners.

Actual root cause

SafeTimespanGuarantor (per-named-update independent gates) was replaced in #1652 with a single shared mutex+CV+counter FrameCompletionScope gate. JS-thread SubmitCommands and similar must acquire a scope, which blocks on m_frameSyncCV while m_frameBlocked == true.

The unit-test pump was changed to:

while (!ready) {
    Start;        // open gate, notify_all
    Finish;       // wait scopes==0, close gate, bgfx::frame()
    wait_for(16ms);
}

The window between Start and Finish is ~zero. JS thread woken by notify_all has to win a scheduler race against the pump thread re-acquiring the mutex inside Finish to land its scope before the gate closes. On contended runners JS loses that race repeatedly → 16 ms + bgfx::frame() per missed scope → tests that should run 4 s take 30+ min.

Fix

Invert the pump so the gate stays open during wait_for:

Start;
while (true) {
    wait_for(16ms);   // gate OPEN here, JS thread can submit freely
    if (ready) break;
    Finish;
    Start;
}

Validation

Applied the fix on bghgary/unittest-watchdog (commit 140894be). 4 parallel runs × 2 jobs each = 8 jobs:

Run	Job	Total	Unit Tests step
25085490269	gcc	359 s	4 s
25085490269	clang	393 s	4 s
25085504626	gcc	355 s	4 s
25085504626	clang	384 s	4 s
25085506892	gcc	364 s	4 s
25085506892	clang	352 s	4 s
25085508987	gcc	362 s	4 s
25085508987	clang	377 s	4 s

All 4-second Unit Tests, total 352–393 s — back in master baseline range. Variance gone.

Open question

Should the fix live in the test pump only (committed), or also propose a change to the FrameCompletionScope gate model in #1652? Real-world consumers (Playground apps) drive Start/Finish from OS event loops with natural delays, so they likely don't hit this race the way the test pump does. Test-only is small and provably fixes CI; gate-model change is the more architectural fix but is in scope of #1652 itself. Will discuss with @bghgary on his return.

Reverted the unrelated LIBGL_ALWAYS_SOFTWARE env-var fix (it was a no-op for this).