test(scriptworker): tight-heartbeat tests warm the worker before arming the 3-interval silence kill (#827 audit)
A_burst_of_cold_compiles_does_not_starve_the_heartbeat (50 ms heartbeat) and A_caller_that_blocks_after_its_result_does_not_starve_the_reader (100 ms) launched their worker under the tight silence kill, so its cold start (launch, first compile, Roslyn JIT) had to stay within 150/300 ms of silence. Under 28 busy processes on 14 cores that failed 2 in 10 runs in the WARM-UP, killed for ~165 ms of silence, and replacement workers were killed the same way. New test seam: WorkerLaunchSpec.HeartbeatSilenceLimit (runner internal ctor heartbeatSilenceLimit) and WorkerConnection.SilenceLimit. The tests launch with a 30 s limit, warm, then tighten to three intervals for the phase they are about; the assertions on that phase are unchanged.
This commit is contained in:
@@ -81,6 +81,10 @@ internal sealed record BatchSubmission(string Key, EvalRequest Request, TimeSpan
|
||||
/// Windows only: the worker identity's SID (<c>Scripting:Worker:Identity</c>). Set, the worker starts under a restricted
|
||||
/// token (<see cref="RestrictedWorkerLauncher"/>) and the pipe ACL admits it beside the host; null keeps the host's token.
|
||||
/// </param>
|
||||
/// <param name="HeartbeatSilenceLimit">
|
||||
/// How long the worker may send nothing before it is killed (<see cref="WorkerExitReason.KilledHeartbeat"/>); null =
|
||||
/// three <paramref name="HeartbeatInterval"/>s. Test seam (with <see cref="WorkerConnection.SilenceLimit"/>).
|
||||
/// </param>
|
||||
/// <param name="WorkerSoftClock">
|
||||
/// Ask the worker to run the soft clock from each run's start (lmxopcua#827; see <see cref="WorkerConnection.WorkerSoftClock"/>).
|
||||
/// False (tests only) keeps the pre-#827 host clock, which is also what a worker that does not echo it gets.
|
||||
@@ -99,7 +103,8 @@ internal sealed record WorkerLaunchSpec(
|
||||
TimeSpan? LoadTimeout = null,
|
||||
int CompileThreads = 0,
|
||||
string? WorkerSid = null,
|
||||
bool WorkerSoftClock = true)
|
||||
bool WorkerSoftClock = true,
|
||||
TimeSpan? HeartbeatSilenceLimit = null)
|
||||
{
|
||||
/// <summary>The default compile timeout.</summary>
|
||||
public static readonly TimeSpan DefaultLoadTimeout = TimeSpan.FromSeconds(60);
|
||||
@@ -156,7 +161,7 @@ internal sealed class WorkerConnection : IAsyncDisposable
|
||||
|
||||
private WorkerConnection(string shard, Process process, NamedPipeServerStream pipe, IDisposable? job, IDisposable? stdio,
|
||||
string workDir, ILogger log, Action<LogBatch> onLogs, TimeSpan heartbeatInterval, TimeSpan loadTimeout,
|
||||
Action<WorkerExit> onExiting, string? markerPath, bool workerSoftClock)
|
||||
Action<WorkerExit> onExiting, string? markerPath, bool workerSoftClock, TimeSpan? heartbeatSilenceLimit)
|
||||
{
|
||||
WorkerSoftClock = workerSoftClock;
|
||||
_stdio = stdio;
|
||||
@@ -171,6 +176,7 @@ internal sealed class WorkerConnection : IAsyncDisposable
|
||||
_log = log;
|
||||
_onLogs = onLogs;
|
||||
_heartbeatInterval = heartbeatInterval;
|
||||
_silenceLimitTicks = (heartbeatSilenceLimit ?? heartbeatInterval * 3).Ticks;
|
||||
Pid = process.Id;
|
||||
// The handshake used seq 1. A failed write means the pipe is gone: the worker is dead or dying.
|
||||
_writer = new ScriptWorkerFrameWriter(pipe, OnWriteFault, ScriptWorkerFrameCodec.DefaultMaxFrameBytes, firstSeq: 1,
|
||||
@@ -215,6 +221,20 @@ internal sealed class WorkerConnection : IAsyncDisposable
|
||||
set => _loadTimeout = value;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// How long the worker may send nothing before it is killed for silence: three heartbeat intervals unless the
|
||||
/// launch spec said otherwise. Test hook: a test with a tight heartbeat launches and warms the worker (its cold
|
||||
/// start JITs Roslyn, which on a loaded box can pause it for longer than three short intervals) under a generous
|
||||
/// limit, then tightens it for the phase it is about.
|
||||
/// </summary>
|
||||
internal TimeSpan SilenceLimit
|
||||
{
|
||||
get => TimeSpan.FromTicks(Volatile.Read(ref _silenceLimitTicks));
|
||||
set => Volatile.Write(ref _silenceLimitTicks, value.Ticks);
|
||||
}
|
||||
|
||||
private long _silenceLimitTicks;
|
||||
|
||||
/// <summary>Compiles currently outstanding on this worker.</summary>
|
||||
public int LoadingCount => _loads.Count;
|
||||
|
||||
@@ -327,7 +347,8 @@ internal sealed class WorkerConnection : IAsyncDisposable
|
||||
: await HandshakeAsync(pipe, hello, nonce, process.Id, handshakeCts.Token).ConfigureAwait(false);
|
||||
|
||||
var connection = new WorkerConnection(spec.Shard, process, pipe, job, stdio, workDir, log, onLogs, spec.HeartbeatInterval,
|
||||
spec.EffectiveLoadTimeout, onExiting, markerPath, workerSoftClock: spec.WorkerSoftClock && ready.WorkerSoftClock);
|
||||
spec.EffectiveLoadTimeout, onExiting, markerPath, workerSoftClock: spec.WorkerSoftClock && ready.WorkerSoftClock,
|
||||
heartbeatSilenceLimit: spec.HeartbeatSilenceLimit);
|
||||
connection.Begin();
|
||||
return connection;
|
||||
}
|
||||
@@ -888,7 +909,7 @@ internal sealed class WorkerConnection : IAsyncDisposable
|
||||
{
|
||||
if (_exited.Task.IsCompleted) return;
|
||||
var silent = Stopwatch.GetElapsedTime(Volatile.Read(ref _lastFrameTimestamp));
|
||||
if (silent > _heartbeatInterval * 3)
|
||||
if (silent > SilenceLimit)
|
||||
{
|
||||
_log.Warning("ScriptWorker[{Shard}] pid {Pid} sent nothing for {Silent} ms; killing it", Shard, Pid, (long)silent.TotalMilliseconds);
|
||||
Kill(WorkerExitReason.KilledHeartbeat, null);
|
||||
|
||||
Reference in New Issue
Block a user