using System.Diagnostics; using System.Runtime.InteropServices; using System.Security.Cryptography; using System.Text; using Serilog; using Shouldly; using Xunit; using ZB.MOM.WW.OtOpcUa.Core.Scripting; using ZB.MOM.WW.OtOpcUa.Core.Scripting.OutOfProcess; using ZB.MOM.WW.OtOpcUa.Core.Scripting.Protocol.V1; namespace ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests; /// /// lmxopcua#827: the soft deadline T starts when an evaluation thread starts the run — the worker runs that clock — /// so the pipe round trip and the time a starved worker takes to START the run no longer count against the script. /// From the start it is wall-clock time, as in process: a pause DURING the run still counts, and is not tested /// here (a mid-run freeze races the script's own return against the watchdog's notice). The host keeps a transport deadline (T + G from submit) and reports passing /// it as a runner fault (, BadResourceUnavailable), never as a /// script timeout. The starved worker is made real here: its process is suspended (SIGSTOP / NtSuspendProcess) /// while a trivial script is submitted. /// [Collection(ScriptWorkerCollection.Name)] [Trait("Category", "ScriptWorker")] public sealed class WorkerSoftClockTests { private const string Trivial = "return 7;"; private const string Runaway = "while (true) { }"; private static CancellationToken Ct => TestContext.Current.CancellationToken; /// /// A runner whose worker heartbeats every 2 s, so the host's silence kill (3 intervals) stays well clear of the /// suspensions below: what is measured is the deadline, not the heartbeat monitor. /// private static OutOfProcessScriptRunner Runner(TimeSpan hardGrace, ILogger? log = null) => new(Scripts.Options(hardGrace: hardGrace, quarantineAfterKills: 1), log ?? new LoggerConfiguration().CreateLogger(), null, heartbeatInterval: TimeSpan.FromSeconds(2), loadTimeout: TimeSpan.FromSeconds(60)); private static async Task WarmAsync(OutOfProcessScriptRunner runner, string key) { var warm = await runner.RunAsync(Scripts.Vt(key, Trivial, TimeSpan.FromSeconds(30)), Ct); warm.Status.ShouldBe(ScriptRunStatus.Ok, warm.Reason); var worker = runner.Shards[0].Current.ShouldNotBeNull(); worker.WorkerSoftClock.ShouldBeTrue("the worker negotiated the soft clock"); return worker; } /// /// The issue's headline: a worker that cannot be scheduled for longer than T, but shorter than the transport /// deadline, answers a trivial script with its value. Before #827 the host's clock, started at submit, answered /// script timed out after 0.3s for return 7;. /// [Fact] public async Task A_worker_stalled_for_longer_than_T_still_answers_a_trivial_script_with_its_value() { var softT = TimeSpan.FromMilliseconds(300); await using var runner = Runner(hardGrace: TimeSpan.FromSeconds(3)); var worker = await WarmAsync(runner, "trivial"); Task run; using (ProcessFreezer.Freeze(worker.Pid)) { run = runner.RunAsync(Scripts.Vt("trivial", Trivial, softT), Ct); await Task.Delay(softT * 4, Ct); // 1.2 s: well past T on the host's clock run.IsCompleted.ShouldBeFalse("nothing can answer while the worker is suspended"); } var outcome = await run.WaitAsync(TimeSpan.FromSeconds(30), Ct); outcome.Status.ShouldBe(ScriptRunStatus.Ok, outcome.Reason); outcome.Value.ShouldBe(7); runner.Shards[0].Current.ShouldNotBeNull().Pid.ShouldBe(worker.Pid, "a stall is not a deadline kill"); runner.QuarantinedKeys(ScriptContextKind.VirtualTag).ShouldBeEmpty(); } /// /// A stall past the transport deadline (T + G) is the runner's fault: the caller gets /// as (published /// BadResourceUnavailable) with a recovery that completes when the worker answers; a re-trigger meanwhile is the /// runner's fault too (not "previous run still running"); the worker is not killed and the key is not struck. /// Before #827 this was a script timeout at T and a deadline kill at T + G that struck the key — with /// QuarantineAfterKills = 1, a quarantine for return 7;. /// [Fact] public async Task A_worker_stalled_past_the_transport_deadline_is_a_runner_fault_and_nothing_is_struck() { var softT = TimeSpan.FromMilliseconds(200); var grace = TimeSpan.FromMilliseconds(400); await using var runner = Runner(grace); var worker = await WarmAsync(runner, "trivial"); // Review F5: both answers are counted (otopcua.script.ipc.timeouts, answer = stalled | retrigger). var answers = new System.Collections.Concurrent.ConcurrentQueue(); using var listener = new System.Diagnostics.Metrics.MeterListener(); listener.InstrumentPublished = (instrument, l) => { if (instrument.Name == "otopcua.script.ipc.timeouts") l.EnableMeasurementEvents(instrument); }; listener.SetMeasurementEventCallback((_, _, tags, _) => { foreach (var tag in tags) if (tag.Key == "answer") answers.Enqueue((string)tag.Value!); }); listener.Start(); ScriptRunOutcome stalled, retriggered; using (ProcessFreezer.Freeze(worker.Pid)) { stalled = await runner.RunAsync(Scripts.Vt("trivial", Trivial, softT), Ct).WaitAsync(TimeSpan.FromSeconds(10), Ct); retriggered = await runner.RunAsync(Scripts.Vt("trivial", Trivial, softT), Ct).WaitAsync(TimeSpan.FromSeconds(10), Ct); stalled.Recovery.ShouldNotBeNull().IsCompleted.ShouldBeFalse("the worker has not answered yet"); } stalled.Status.ShouldBe(ScriptRunStatus.Unavailable, stalled.Reason); stalled.Reason.ShouldBe(ScriptRunOutcome.WorkerUnresponsiveReason); retriggered.Status.ShouldBe(ScriptRunStatus.Unavailable, retriggered.Reason); retriggered.Reason.ShouldBe(ScriptRunOutcome.WorkerUnresponsiveReason); stalled.ToVirtualTagEvalResult().StatusCode.ShouldBe(Commons.OpcUa.OpcUaStatus.BadResourceUnavailable); answers.ToArray().ShouldBe(["stalled", "retrigger"], ignoreOrder: true); await stalled.Recovery!.WaitAsync(TimeSpan.FromSeconds(30), Ct); var next = await runner.RunAsync(Scripts.Vt("trivial", Trivial, softT), Ct); next.Status.ShouldBe(ScriptRunStatus.Ok, next.Reason); next.Value.ShouldBe(7); runner.Shards[0].Current.ShouldNotBeNull().Pid.ShouldBe(worker.Pid, "a stall is not a deadline kill"); runner.QuarantinedKeys(ScriptContextKind.VirtualTag).ShouldBeEmpty(); } /// /// The other side of the contract is unchanged: a script that really runs past T is answered at T from its own /// start and killed G after that, even with the worker stalled before it started. Positive control for the two /// tests above — they would also pass if the runner simply never timed anything out. /// [Fact] public async Task A_runaway_that_starts_late_is_still_timed_out_at_T_from_its_start_and_killed_at_G() { var softT = TimeSpan.FromMilliseconds(300); var grace = TimeSpan.FromMilliseconds(600); var stall = TimeSpan.FromMilliseconds(500); await using var runner = Runner(grace); var worker = await WarmAsync(runner, "warm"); var load = await runner.RunAsync(Scripts.Vt("runaway", "return 0;", TimeSpan.FromSeconds(30)), Ct); load.Status.ShouldBe(ScriptRunStatus.Ok, load.Reason); var sw = Stopwatch.StartNew(); Task run; using (ProcessFreezer.Freeze(worker.Pid)) { run = runner.RunAsync(Scripts.Vt("runaway", Runaway, softT), Ct); await Task.Delay(stall, Ct); } var thawed = sw.Elapsed; var outcome = await run.WaitAsync(TimeSpan.FromSeconds(30), Ct); var answered = sw.Elapsed; outcome.Status.ShouldBe(ScriptRunStatus.Failed); outcome.Reason.ShouldNotBeNull().ShouldStartWith("script timed out after "); (answered - thawed).ShouldBeGreaterThanOrEqualTo(softT - TimeSpan.FromMilliseconds(50), "T counts from the run's start, after the stall"); var exit = await worker.Exited.WaitAsync(TimeSpan.FromSeconds(30), Ct); exit.Reason.ShouldBe(WorkerExitReason.KilledDeadline); exit.CulpritKey.ShouldBe(InProcessScriptRunner.ScopedKey(ScriptContextKind.VirtualTag, "runaway")); (sw.Elapsed - thawed).ShouldBeGreaterThanOrEqualTo(softT + grace - TimeSpan.FromMilliseconds(50), "G counts from the soft deadline"); } /// /// Shadow (lmxopcua#780 P2) compares the shadow pool with the published in-process result; a starved worker used to /// show up there as a script mismatch (published Ok, shadow "timed out") and skew the census for the OutOfProcess /// flip. Now a stall shorter than the transport deadline is a match, and a longer one is shadow_unavailable /// — never a mismatch — including the re-trigger that finds the stalled run still holding its slot. /// [Fact] public async Task In_Shadow_a_stalled_worker_is_a_match_or_shadow_unavailable_never_a_mismatch() { var softT = TimeSpan.FromMilliseconds(300); var grace = TimeSpan.FromSeconds(1); var options = Scripts.Options(hardGrace: grace, quarantineAfterKills: 1); options.Runner = ScriptRunnerMode.Shadow; await using var pool = Runner(grace); using var shadow = new ShadowScriptRunner(pool, options, new LoggerConfiguration().CreateLogger()); var worker = await WarmAsync(pool, "trivial"); var published = ScriptRunOutcome.Ok(7); // Stall past T, short of T + G: compared, and a match. using (ProcessFreezer.Freeze(worker.Pid)) { shadow.Mirror(Scripts.Vt("trivial", Trivial, softT), published); await Task.Delay(TimeSpan.FromMilliseconds(900), Ct); } (await shadow.WaitIdleAsync(TimeSpan.FromSeconds(30))).ShouldBeTrue(); shadow.Stats().Matched.ShouldBe(1, Summary(shadow)); // Stall past T + G: not compared. The second mirror arrives while the first still holds the key's slot. using (ProcessFreezer.Freeze(worker.Pid)) { shadow.Mirror(Scripts.Vt("trivial", Trivial, softT), published); await Scripts.Eventually(() => shadow.Stats().ShadowUnavailable == 1, TimeSpan.FromSeconds(10), "the transport deadline"); shadow.Mirror(Scripts.Vt("trivial", Trivial, softT), published); await Scripts.Eventually(() => shadow.Stats().ShadowUnavailable == 2, TimeSpan.FromSeconds(10), "the stalled re-trigger"); } (await shadow.WaitIdleAsync(TimeSpan.FromSeconds(30))).ShouldBeTrue(); var stats = shadow.Stats(); stats.Mismatched.ShouldBe(0, Summary(shadow)); stats.ShadowUnavailable.ShouldBe(2, Summary(shadow)); stats.Matched.ShouldBe(1); pool.Shards[0].Current.ShouldNotBeNull().Pid.ShouldBe(worker.Pid); } /// /// Protocol compatibility: the soft clock is negotiated (Hello.worker_soft_clock → Ready.worker_soft_clock). /// A host that does not ask for it keeps the pre-#827 contract — the soft deadline is the host's, from submit, /// and the worker sends no soft notices — and a runaway is still answered at T and killed at T + G. /// [Theory] [InlineData(true)] [InlineData(false)] public async Task The_soft_clock_is_negotiated_and_both_clocks_enforce_T_and_G(bool workerSoftClock) { var spec = new WorkerLaunchSpec("t", OutOfProcessScriptRunner.ResolveWorkerPath(new ScriptWorkerOptions { ExecutablePath = Scripts.WorkerUnderTest }), 256L * 1024 * 1024, EvalThreads: 2, HardGrace: TimeSpan.FromSeconds(1), HeartbeatInterval: TimeSpan.FromSeconds(1), HandshakeTimeout: TimeSpan.FromSeconds(15), WorkerSoftClock: workerSoftClock); var connection = await WorkerConnection.StartAsync(spec, new LoggerConfiguration().CreateLogger(), _ => { }, _ => { }, Ct); await using var _ = connection; connection.WorkerSoftClock.ShouldBe(workerSoftClock); var entry = await connection.EnsureLoadedAsync("k", ContextKind.VirtualTag, Runaway, SHA256.HashData(Encoding.UTF8.GetBytes(Runaway)), []).WaitAsync(TimeSpan.FromSeconds(60), Ct); entry.Outcome.ShouldNotBeNull().Ok.ShouldBeTrue(); var softT = TimeSpan.FromMilliseconds(300); var grace = TimeSpan.FromMilliseconds(500); var sw = Stopwatch.StartNew(); var pending = connection.Submit("k", new EvalRequest { Key = "k", SoftTimeoutMs = (uint)softT.TotalMilliseconds, HardGraceMs = (uint)grace.TotalMilliseconds, NowUtcTicks = DateTime.UtcNow.Ticks }, softT, grace, null); (await pending.Outcome.WaitAsync(TimeSpan.FromSeconds(10), Ct)).ShouldBeSameAs(PendingEval.SoftTimedOut); sw.Elapsed.ShouldBeGreaterThanOrEqualTo(softT - TimeSpan.FromMilliseconds(20)); connection.Cancel(pending); var exit = await connection.Exited.WaitAsync(TimeSpan.FromSeconds(10), Ct); exit.Reason.ShouldBe(WorkerExitReason.KilledDeadline); sw.Elapsed.ShouldBeGreaterThanOrEqualTo(softT + grace - TimeSpan.FromMilliseconds(50)); } // ---------------------------------------------------------------- review findings (#827) /// /// Review F1: the soft notice is handled on the pipe READER, and the caller's resumption is the caller's code. It /// must go through the result dispatcher like a result does: a continuation that blocks for 1.5 s must not hold up /// the reader, or the next heartbeats sit unread and a healthy worker is killed for silence (300 ms here). Before /// the fix the continuation ran inline on the reader and the worker was killed (KilledHeartbeat). /// [Fact] public async Task A_slow_continuation_of_a_soft_timeout_does_not_stall_the_reader() { var heartbeat = TimeSpan.FromMilliseconds(100); var spec = new WorkerLaunchSpec("t", OutOfProcessScriptRunner.ResolveWorkerPath(new ScriptWorkerOptions { ExecutablePath = Scripts.WorkerUnderTest }), 256L * 1024 * 1024, EvalThreads: 2, HardGrace: TimeSpan.FromSeconds(60), HeartbeatInterval: heartbeat, HandshakeTimeout: TimeSpan.FromSeconds(15), HeartbeatSilenceLimit: TimeSpan.FromSeconds(30)); var connection = await WorkerConnection.StartAsync(spec, new LoggerConfiguration().CreateLogger(), _ => { }, _ => { }, Ct); await using var _ = connection; var entry = await connection.EnsureLoadedAsync("k", ContextKind.VirtualTag, Runaway, SHA256.HashData(Encoding.UTF8.GetBytes(Runaway)), []).WaitAsync(TimeSpan.FromSeconds(60), Ct); entry.Outcome.ShouldNotBeNull().Ok.ShouldBeTrue(); connection.SilenceLimit = heartbeat * 3; // armed only once the cold start is over (see SupervisionTests) var softT = TimeSpan.FromMilliseconds(200); var pending = connection.Submit("k", new EvalRequest { Key = "k", SoftTimeoutMs = (uint)softT.TotalMilliseconds, HardGraceMs = 60_000, NowUtcTicks = DateTime.UtcNow.Ticks }, softT, TimeSpan.FromSeconds(60), null); string? resumedOn = null; var slowConsumer = pending.Outcome.ContinueWith(t => { resumedOn = Thread.CurrentThread.Name; t.Result.ShouldBeSameAs(PendingEval.SoftTimedOut); Thread.Sleep(1_500); }, CancellationToken.None, TaskContinuationOptions.ExecuteSynchronously, TaskScheduler.Default); await slowConsumer.WaitAsync(TimeSpan.FromSeconds(10), Ct); resumedOn.ShouldBe("ScriptWorker[t].Results", "the caller resumes on the dispatcher, never on the reader"); connection.Exited.IsCompleted.ShouldBeFalse("the reader kept reading heartbeats while the consumer was slow"); connection.IsAlive.ShouldBeTrue(); } /// /// Review F2: a stall past T + G answers "worker unresponsive"; when the worker then runs the script and it really /// overruns T, the late soft notice must still cancel its token — a polling script ends itself instead of the whole /// worker being killed G later — and the run counts as a timeout (QuarantineAfterConsecutiveTimeouts = 1 here). /// Before the fix nobody sent the Cancel: the worker was killed at notice + G (KilledDeadline, a kill strike). /// [Fact] public async Task A_slow_script_whose_notice_arrives_after_the_transport_deadline_is_cancelled_and_counted_not_killed() { var softT = TimeSpan.FromMilliseconds(200); var grace = TimeSpan.FromMilliseconds(400); var options = Scripts.Options(hardGrace: grace, quarantineAfterKills: 1); options.QuarantineAfterConsecutiveTimeouts = 1; await using var runner = new OutOfProcessScriptRunner(options, new LoggerConfiguration().CreateLogger(), null, heartbeatInterval: TimeSpan.FromSeconds(2), loadTimeout: TimeSpan.FromSeconds(60)); const string polite = "if ((int)ctx.GetTag(\"spin\").Value == 1) { while (!ctx.CancellationToken.IsCancellationRequested) { } } return 1;"; (await runner.RunAsync(Scripts.Vt("polite", polite, TimeSpan.FromSeconds(30), Scripts.Input("spin", 0)), Ct)).Value.ShouldBe(1); var worker = runner.Shards[0].Current.ShouldNotBeNull(); ScriptRunOutcome stalled; using (ProcessFreezer.Freeze(worker.Pid)) { stalled = await runner.RunAsync(Scripts.Vt("polite", polite, softT, Scripts.Input("spin", 1)), Ct).WaitAsync(TimeSpan.FromSeconds(10), Ct); } stalled.Reason.ShouldBe(ScriptRunOutcome.WorkerUnresponsiveReason); // Thawed: the script starts, spins past T, the late notice cancels it and it returns. The worker survives G. await stalled.Recovery.ShouldNotBeNull().WaitAsync(TimeSpan.FromSeconds(10), Ct); await Task.Delay(softT + grace + TimeSpan.FromMilliseconds(500), Ct); worker.IsAlive.ShouldBeTrue("a cancelled polling script must not cost its worker"); runner.Shards[0].Current.ShouldNotBeNull().Pid.ShouldBe(worker.Pid); // …and it counted as the timeout it was (threshold 1), not as a kill. await Scripts.Eventually(() => runner.QuarantinedKeys(ScriptContextKind.VirtualTag).Count == 1, TimeSpan.FromSeconds(5), "the timeout quarantine"); var refused = await runner.RunAsync(Scripts.Vt("polite", polite, softT, Scripts.Input("spin", 0)), Ct); refused.Reason.ShouldNotBeNull().ShouldContain("timed out"); refused.Reason.ShouldNotContain("hard deadline"); } /// /// Review F3: the host keeps its own bound. A worker that heartbeats but never sends a soft notice (a bug, or a /// compromised worker — simulated by the host dropping its notices) used to hold the run, the key's slot and the /// tag's BadResourceUnavailable forever: the transport deadline answers the caller once and the kill G is armed /// only by a notice. Now no progress for the ceiling, with evaluations outstanding, kills the worker /// (, no culprit) and the run completes. G is 60 s here, so the /// worker's own fail-fast watchdog (notice + G + 0.5 s) cannot be what ends it. /// [Fact] public async Task A_worker_that_heartbeats_but_never_reports_progress_is_killed_at_the_host_ceiling() { var spec = new WorkerLaunchSpec("t", OutOfProcessScriptRunner.ResolveWorkerPath(new ScriptWorkerOptions { ExecutablePath = Scripts.WorkerUnderTest }), 256L * 1024 * 1024, EvalThreads: 2, HardGrace: TimeSpan.FromSeconds(60), HeartbeatInterval: TimeSpan.FromMilliseconds(200), HandshakeTimeout: TimeSpan.FromSeconds(15), HeartbeatSilenceLimit: TimeSpan.FromSeconds(30)); var connection = await WorkerConnection.StartAsync(spec, new LoggerConfiguration().CreateLogger(), _ => { }, _ => { }, Ct); await using var _ = connection; var entry = await connection.EnsureLoadedAsync("k", ContextKind.VirtualTag, Runaway, SHA256.HashData(Encoding.UTF8.GetBytes(Runaway)), []).WaitAsync(TimeSpan.FromSeconds(60), Ct); entry.Outcome.ShouldNotBeNull().Ok.ShouldBeTrue(); connection.DropSoftNoticesForTest = true; connection.ProgressCeilingOverride = TimeSpan.FromSeconds(1.5); var softT = TimeSpan.FromMilliseconds(200); var sw = Stopwatch.StartNew(); var pending = connection.Submit("k", new EvalRequest { Key = "k", SoftTimeoutMs = (uint)softT.TotalMilliseconds, HardGraceMs = 60_000, NowUtcTicks = DateTime.UtcNow.Ticks }, softT, TimeSpan.FromSeconds(60), null); var exit = await connection.Exited.WaitAsync(TimeSpan.FromSeconds(15), Ct); exit.Reason.ShouldBe(WorkerExitReason.KilledUnresponsive); exit.CulpritKey.ShouldBeNull("nothing says which script, so nothing is struck"); exit.InFlightKeys.ShouldBe(["k"]); sw.Elapsed.ShouldBeGreaterThanOrEqualTo(TimeSpan.FromSeconds(1.4), "not before the ceiling"); (await pending.Completion.WaitAsync(TimeSpan.FromSeconds(5), Ct)).ShouldBeNull("the run is released"); } /// Positive control for the ceiling: the default rule leaves a busy, answering worker alone. [Fact] public async Task The_progress_ceiling_leaves_a_worker_that_keeps_answering_alone() { var spec = new WorkerLaunchSpec("t", OutOfProcessScriptRunner.ResolveWorkerPath(new ScriptWorkerOptions { ExecutablePath = Scripts.WorkerUnderTest }), 256L * 1024 * 1024, EvalThreads: 1, HardGrace: TimeSpan.FromSeconds(60), HeartbeatInterval: TimeSpan.FromMilliseconds(100), HandshakeTimeout: TimeSpan.FromSeconds(15), HeartbeatSilenceLimit: TimeSpan.FromSeconds(30)); var connection = await WorkerConnection.StartAsync(spec, new LoggerConfiguration().CreateLogger(), _ => { }, _ => { }, Ct); await using var _ = connection; const string spin = "var end = ctx.Now.AddMilliseconds(150); while (ctx.Now < end) { } return 1;"; var entry = await connection.EnsureLoadedAsync("k", ContextKind.VirtualTag, spin, SHA256.HashData(Encoding.UTF8.GetBytes(spin)), []).WaitAsync(TimeSpan.FromSeconds(60), Ct); entry.Outcome.ShouldNotBeNull().Ok.ShouldBeTrue(); // Ceiling 1 s; 20 runs of 150 ms queued behind one evaluation thread take ~3 s, but each answers. connection.ProgressCeilingOverride = TimeSpan.FromSeconds(1); var soft = TimeSpan.FromSeconds(30); var pendings = connection.SubmitBatch(Enumerable.Range(0, 20).Select(_ => new BatchSubmission("k", new EvalRequest { Key = "k", SoftTimeoutMs = 30_000, HardGraceMs = 60_000, NowUtcTicks = DateTime.UtcNow.Ticks }, soft, TimeSpan.FromSeconds(60), null)).ToArray()); foreach (var p in pendings) (await p.Completion.WaitAsync(TimeSpan.FromSeconds(30), Ct)).ShouldNotBeNull(); connection.IsAlive.ShouldBeTrue(); } // ---------------------------------------------------------------- PendingEval, no process /// The host side of the worker clock, deterministic: no notice means the transport deadline at T + G. [Fact] public async Task Worker_clock_with_no_word_from_the_worker_answers_transport_timed_out_at_T_plus_G_and_never_kills() { var killed = 0; var pending = new PendingEval("k", 1); var sw = Stopwatch.StartNew(); pending.Arm(TimeSpan.FromMilliseconds(100), TimeSpan.FromMilliseconds(200), _ => Interlocked.Increment(ref killed), workerClock: true); (await pending.Outcome.WaitAsync(TimeSpan.FromSeconds(10), Ct)).ShouldBeSameAs(PendingEval.TransportTimedOut); sw.Elapsed.ShouldBeGreaterThanOrEqualTo(TimeSpan.FromMilliseconds(280)); await Task.Delay(500, Ct); killed.ShouldBe(0, "a late worker is not the script's fault"); // A soft notice after the transport answer still arms the kill: the script itself ran for T. pending.SoftExpired(); await Scripts.Eventually(() => Volatile.Read(ref killed) == 1, TimeSpan.FromSeconds(10), "the kill G after the soft notice"); } /// The soft notice answers the caller and arms the kill G later; a result before then cancels it. [Fact] public async Task Worker_clock_soft_notice_answers_soft_timed_out_and_arms_the_kill_G_later() { var killed = 0; var pending = new PendingEval("k", 1); pending.Arm(TimeSpan.FromSeconds(30), TimeSpan.FromMilliseconds(300), _ => Interlocked.Increment(ref killed), workerClock: true); pending.Outcome.IsCompleted.ShouldBeFalse(); var sw = Stopwatch.StartNew(); pending.SoftExpired(); (await pending.Outcome.WaitAsync(TimeSpan.FromSeconds(1), Ct)).ShouldBeSameAs(PendingEval.SoftTimedOut); await Scripts.Eventually(() => Volatile.Read(ref killed) == 1, TimeSpan.FromSeconds(10), "the kill"); sw.Elapsed.ShouldBeGreaterThanOrEqualTo(TimeSpan.FromMilliseconds(280)); var answered = new PendingEval("k2", 2); answered.Arm(TimeSpan.FromSeconds(30), TimeSpan.FromMilliseconds(100), _ => Interlocked.Increment(ref killed), workerClock: true); answered.SoftExpired(); answered.Complete(new EvalResult { EvalId = 2 }); await Task.Delay(400, Ct); killed.ShouldBe(1, "a run that answered inside G is not killed"); } /// Under the host clock a soft notice means nothing (a worker that did not negotiate it cannot send one). [Fact] public void Host_clock_ignores_a_soft_notice() { var pending = new PendingEval("k", 1); pending.Arm(TimeSpan.FromSeconds(30), TimeSpan.FromSeconds(30), _ => { }, workerClock: false); pending.SoftExpired(); pending.Outcome.IsCompleted.ShouldBeFalse(); pending.Complete(null); } private static string Summary(ShadowScriptRunner shadow) => $"{shadow.Stats()}; " + string.Join("; ", shadow.Mismatches.Select(m => $"{m.Key}: {m.LastReason} — {m.LastSummary}")); } /// Suspends a process (SIGSTOP, or NtSuspendProcess on Windows) until disposed. internal sealed class ProcessFreezer : IDisposable { private readonly int _pid; private int _thawed; private ProcessFreezer(int pid) { _pid = pid; Signal(pid, stop: true); } public static ProcessFreezer Freeze(int pid) => new(pid); public void Dispose() { if (Interlocked.Exchange(ref _thawed, 1) == 0) Signal(_pid, stop: false); } private static void Signal(int pid, bool stop) { if (OperatingSystem.IsWindows()) { using var process = Process.GetProcessById(pid); var status = stop ? NtSuspendProcess(process.Handle) : NtResumeProcess(process.Handle); status.ShouldBe(0, $"Nt{(stop ? "Suspend" : "Resume")}Process"); return; } // libc kill(2), not the kill(1) command: a child process's exit is observed through the same SIGCHLD // handling that the suspended worker (another child of this process) just disturbed, and WaitForExit was // seen to take seconds. var signal = stop ? SigStop : SigCont; Kill(pid, signal).ShouldBe(0, $"kill({pid}, {signal}): errno {Marshal.GetLastPInvokeError()}"); } /// SIGSTOP / SIGCONT: 17 / 19 on macOS (BSD), 19 / 18 on Linux. private static int SigStop => OperatingSystem.IsMacOS() ? 17 : 19; private static int SigCont => OperatingSystem.IsMacOS() ? 19 : 18; #pragma warning disable SYSLIB1054 // DllImport kept: LibraryImport would need AllowUnsafeBlocks for three test-only calls. [DllImport("libc", EntryPoint = "kill", SetLastError = true)] private static extern int Kill(int pid, int signal); [DllImport("ntdll.dll")] private static extern int NtSuspendProcess(IntPtr processHandle); [DllImport("ntdll.dll")] private static extern int NtResumeProcess(IntPtr processHandle); #pragma warning restore SYSLIB1054 }