dohertj2/lmxopcua
1
0
Fork 0
Code Issues 5 Pull Requests Actions Packages Projects Releases Wiki Activity

test(scripting): stuck-orphan quarantine test trusts the guard's young/stuck verdict, not the test's stopwatch (#843)

Browse Source 
Reproduced 4/10 alone under 28 CPU burners (load ~100-250): outcomes were
timeout, refused, refused, quarantined... - the guard right, but the test
labelled a refusal 'young' only if its OWN stopwatch (started before the
first trigger) read < 600 ms, and the first trigger's dispatch + sibling +
cadence ate that. A ScriptRunRefusedException IS the young-orphan answer
(behind a stuck orphan the guard quarantines instead), so: any refusal
before the quarantine proves the rule; stuck factor 50 (3 s) so the second
trigger lands young with room; loop until three quarantined answers; the one
remaining wall-clock check runs the safe way (quarantine time on the test's
stopwatch >= threshold - the orphan is never older than it); runaway is a
held spin so it cannot end on its own; failures print the timeline.
After: 10/10 under the same load.

Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
Joseph Doherty
2026-11-11 03:50:12 -05:00
parent 481985e20b
commit 1696e34868
1 changed files with 60 additions and 25 deletions
Download Patch File Download Diff File Expand all files Collapse all files
tests/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting.Tests/ScriptRunGuardTests.cs
+60 -25
View File
@@ -162,7 +162,7 @@ public sealed class ScriptRunGuardTests
/// <c>while(true)</c> script on a 1 Hz trigger leaked one pool thread per trigger — 30 orphans after 30
/// triggers, trending toward pool starvation. Now the first trigger's orphan is the only one; later
/// triggers are refused while it is young, and once it has run longer than
/// <see cref="ScriptingOptions.StuckOrphanQuarantineFactor"/> × the timeout (10 × 60 ms here — the
/// <see cref="ScriptingOptions.StuckOrphanQuarantineFactor"/> × the timeout (50 × 60 ms here — the
/// trigger cadence is scaled down from 1 Hz to keep the test short) the next refusal quarantines it.
/// A healthy sibling keeps evaluating throughout (the positive control an absence assertion needs).
/// </summary>
@@ -171,44 +171,79 @@ public sealed class ScriptRunGuardTests
/// / <see cref="ScriptRunGuard.StartedRunCount"/>): <see cref="ThreadPool.ThreadCount"/> moves with
/// every parallel test class on a loaded machine, so it is kept as a coarse secondary check only —
/// it must stay far below the 30 the leak would have produced.
/// <para>lmxopcua#843 (failed 2/4 full-suite runs at load average 140–280; 2 of the first 4 runs alone under
/// 28 CPU burners): this used to label a refusal "young" by the TEST's stopwatch, started before the first
/// trigger, and demand one inside 600 ms (10 × 60 ms). Under load the first trigger's dispatch, the sibling
/// and the cadence ate those 600 ms, so the guard's answers were <c>timeout, refused, refused,
/// quarantined…</c> — the guard right, the test's label wrong. Now: the guard is the authority on the
/// orphan's age (a <see cref="ScriptRunRefusedException"/> IS the young-orphan answer; behind a stuck one
/// it quarantines instead), the stuck factor is 50 (3 s) so the second trigger has ample room to land
/// while the orphan is young, the loop runs until the quarantine instead of a fixed 30 triggers, and the
/// one wall-clock check left runs the safe way round — the orphan is never older than the test's
/// stopwatch, so a quarantine before 3 s on it is early on any box. The runaway is a HELD spin (released
/// at the end) so it cannot end on its own and become a second dispatch on a slow box.</para>
/// </remarks>
[Fact]
public async Task Runaway_script_leaves_one_orphan_is_quarantined_once_stuck_and_a_sibling_keeps_evaluating()
{
var guard = new ScriptRunGuard();
using var spin = Compile(SpinScript);
const double stuckFactor = 50;
var guard = new ScriptRunGuard(new ScriptingOptions { StuckOrphanQuarantineFactor = stuckFactor });
using var spin = Compile(BriefSpinScript);
using var fast = Compile(FastScript);
var ct = TestContext.Current.CancellationToken;
var held = new FakeScriptContext();
var threadsBefore = ThreadPool.ThreadCount;
var stuckAfter = ShortTimeout * ScriptingOptions.DefaultStuckOrphanQuarantineFactor; // 600 ms
var stuckAfter = ShortTimeout * stuckFactor; // 3 s
var healthyResults = new List<int>();
var outcomes = new List<string>();
var timeline = new List<string>();
TimeSpan? quarantinedAt = null;
var sw = System.Diagnostics.Stopwatch.StartNew();
for (var trigger = 0; trigger < 30; trigger++)
try
{
try { await Run(guard, "runaway", SpinScript, spin, ShortTimeout, ct); outcomes.Add("value"); }
catch (ScriptTimeoutException) { outcomes.Add("timeout"); }
catch (ScriptRunRefusedException) { outcomes.Add(sw.Elapsed < stuckAfter ? "refused-young" : "refused"); }
catch (ScriptQuarantinedException) { outcomes.Add("quarantined"); }
// At least 30 triggers (the leak's scale), then until three quarantined answers; capped as a hang guard.
for (var trigger = 0; trigger < 1_000 && (trigger < 30 || outcomes.Count(o => o == "quarantined") < 3); trigger++)
{
string outcome;
try { await Run(guard, "runaway", BriefSpinScript, spin, ShortTimeout, ct, held); outcome = "value"; }
catch (ScriptTimeoutException) { outcome = "timeout"; }
catch (ScriptRunRefusedException) { outcome = "refused"; }
catch (ScriptQuarantinedException) { outcome = "quarantined"; quarantinedAt ??= sw.Elapsed; }
outcomes.Add(outcome);
timeline.Add($"#{trigger} {outcome} @{sw.ElapsedMilliseconds}ms");
healthyResults.Add(await Run(guard, "healthy", FastScript, fast, ct: ct));
await Task.Delay(50, ct);
healthyResults.Add(await Run(guard, "healthy", FastScript, fast, ct: ct));
await Task.Delay(50, ct);
}
var triggers = outcomes.Count;
var diagnostics = $"timeline: {string.Join(", ", timeline)}";
guard.InFlightCount.ShouldBe(1, "exactly one orphaned run — the first trigger's — may be executing; " + diagnostics);
guard.StartedRunCount.ShouldBe(1 + triggers, "one dispatch for the runaway script, one per trigger for the healthy sibling; " + diagnostics);
outcomes[0].ShouldBe("timeout", diagnostics);
var firstQuarantine = outcomes.IndexOf("quarantined");
firstQuarantine.ShouldBeGreaterThan(0, "the stuck orphan was never quarantined; " + diagnostics);
outcomes.Take(firstQuarantine).Skip(1).ShouldAllBe(o => o == "refused", diagnostics);
outcomes.Take(firstQuarantine).ShouldContain("refused",
"a young orphan is only refused — a short overrun is not quarantined; " + diagnostics);
outcomes.Skip(firstQuarantine).ShouldAllBe(o => o == "quarantined", diagnostics);
quarantinedAt!.Value.ShouldBeGreaterThanOrEqualTo(stuckAfter,
$"the orphan is never older than the test's stopwatch, so a quarantine before {stuckFactor}x the budget on it is early; " + diagnostics);
guard.IsQuarantined("runaway", out var reason).ShouldBeTrue("the orphan outlived its stuck threshold");
reason!.ShouldContain("stuck");
guard.QuarantinedCount.ShouldBe(1);
healthyResults.ShouldAllBe(v => v == 42);
healthyResults.Count.ShouldBe(triggers);
var threadDelta = ThreadPool.ThreadCount - threadsBefore;
threadDelta.ShouldBeLessThan(15, $"{triggers} leaked orphans would have grown the pool by ~{triggers} threads");
}
guard.InFlightCount.ShouldBe(1, "exactly one orphaned run — the first trigger's — may be executing");
guard.StartedRunCount.ShouldBe(1 + 30, "one dispatch for the runaway script, thirty for the healthy sibling");
outcomes[0].ShouldBe("timeout");
outcomes.ShouldContain("refused-young", "a young orphan is only refused — a short overrun is not quarantined");
guard.IsQuarantined("runaway", out var reason).ShouldBeTrue("the orphan outlived 10x its budget: it is stuck");
reason!.ShouldContain("stuck");
outcomes[^1].ShouldBe("quarantined");
guard.QuarantinedCount.ShouldBe(1);
healthyResults.ShouldAllBe(v => v == 42);
healthyResults.Count.ShouldBe(30);
var threadDelta = ThreadPool.ThreadCount - threadsBefore;
threadDelta.ShouldBeLessThan(15, "thirty leaked orphans would have grown the pool by ~30 threads");
finally
{
held.Released = true;
}
await WaitForIdle(guard);
}
/// <summary>