Spread agent first contact with startup jitter

Both agent loops made their first request the instant the service
started, and the service is installed start=auto - so a patch reboot put
the whole fleet on the wire together, twice per machine (a telemetry
report and a command poll). The existing jitterseconds does not help: it
spreads the gap between runs, not first contact.

Measured on a 700-endpoint burst: simultaneous arrival drove TLS
handshakes to 1482ms worst case and pinned CPU at 305% while the
database sat idle at 3 active queries. Spreading the same arrivals over
30s cut worst-case handshake to 63.7ms with no server-side change. The
server was never the constraint; simultaneity was. Raising the
SQLAlchemy pool was tried and rejected - it moved the queue from
SQLAlchemy into MySQL without adding throughput.

StartupJitter is shared by both workers so the clamp and the
randomisation cannot drift apart between them. Randomised in
milliseconds rather than whole seconds because a 30s window at second
granularity re-clumps a large fleet into 30 buckets of simultaneous
arrivals - the same pile-up in miniature. Clamped to 300s and warned
about when out of range: the command channel is how an operator would
correct a bad value, so an unbounded delay would remove the means of
recovery.

The cost is up to startupjitterseconds of extra latency before a
rebooted endpoint picks up a queued command, on top of a reboot the
machine was already unreachable for. The once-only console switch
bypasses the delay entirely, so smoke tests stay instant.

Agent 1.12.0. Minor because the appsettings schema gains a key; packages
without it fall back to the AgentConfig default. The shipped installer
template in siteagent.py carries the new key, so the containers need
rolling before newly built packages pick it up.
This commit is contained in:
benjamin.baker
2026-09-06 18:08:46 -04:00
parent 6ae251d2ca
commit c078369bb3
8 changed files with 129 additions and 3 deletions

View File

@@ -17,6 +17,23 @@ public sealed class AgentConfig
// (thundering herd). Actual delay = cadence +/- up to jitterseconds.
[JsonPropertyName("jitterseconds")] public int JitterSeconds { get; set; } = 60;
// One-time random delay before FIRST contact, applied by both the telemetry
// and command loops at startup. JitterSeconds only spreads the gap BETWEEN
// runs, so without this every agent in the fleet still makes its first
// request the instant its service starts - and the service is installed
// start=auto, so a patch reboot starts them all together.
//
// Measured on a 700-endpoint burst (devnotes/gevent-sizing-simulation.md):
// simultaneous arrival drove TLS handshakes to 1482ms worst case and pinned
// CPU at 305% while the database sat idle at 3 active queries. Spreading the
// same arrivals over 30s cut worst-case handshake to 63.7ms. The server is
// not the constraint; simultaneity is.
//
// Costs up to this many seconds before a rebooted endpoint picks up a queued
// command. That window is on top of a reboot the machine was already
// unreachable for. 0 disables the delay.
[JsonPropertyName("startupjitterseconds")] public int StartupJitterSeconds { get; set; } = 30;
[JsonPropertyName("adoptonfirstrun")] public bool AdoptOnFirstRun { get; set; } = true;
// Directory holding site-provided PowerShell "agent utilities" the runtime

View File

@@ -41,15 +41,18 @@ public sealed class CommandWorker : BackgroundService
private readonly CommandExecutor executor;
private readonly ILogger<CommandWorker> logger;
private readonly CollectSignal? collectSignal;
private readonly AgentConfig? config;
private readonly string hostname;
public CommandWorker(CommandClient client, CommandExecutor executor,
ILogger<CommandWorker> logger, CollectSignal? collectSignal = null)
ILogger<CommandWorker> logger, CollectSignal? collectSignal = null,
AgentConfig? config = null)
{
this.client = client;
this.executor = executor;
this.logger = logger;
this.collectSignal = collectSignal;
this.config = config;
hostname = Environment.MachineName;
}
@@ -57,6 +60,18 @@ public sealed class CommandWorker : BackgroundService
{
logger.LogInformation("Command channel started for host {Host}", hostname);
// Spread first contact across the fleet. Every agent otherwise polls the
// instant its service starts, and the service is start=auto, so a patch
// reboot puts the whole fleet on the wire together. See StartupJitter.
var startupDelay = StartupJitter.Next(config?.StartupJitterSeconds ?? 0, logger);
if (startupDelay > TimeSpan.Zero)
{
logger.LogInformation(
"Delaying first command poll by {Delay}ms (startup jitter)",
(int)startupDelay.TotalMilliseconds);
await SafeDelay(startupDelay, stoppingToken);
}
while (!stoppingToken.IsCancellationRequested)
{
var pollStarted = System.Diagnostics.Stopwatch.StartNew();

View File

@@ -0,0 +1,51 @@
using Microsoft.Extensions.Logging;
namespace ShopDbEndpointAgent.Core;
// One-time startup delay, shared by TelemetryWorker and CommandWorker.
//
// Both loops otherwise make their first request the instant the service starts,
// and the service is installed start=auto - so a patch-day reboot has an entire
// fleet arriving together, twice per machine (a telemetry report AND a command
// poll). AgentConfig.JitterSeconds does not help: it spreads the gap BETWEEN
// runs, not the first contact.
//
// Lives here rather than in either worker so the two cannot drift apart, and so
// the clamp is enforced in one place.
internal static class StartupJitter
{
// Ceiling on the configured value. A fat-fingered appsettings.json must not
// be able to park an endpoint for hours before it first checks in: the
// command channel is how an operator would correct it, so an unbounded
// delay would take away the means of recovery.
private const int MaxStartupJitterSeconds = 300;
public static TimeSpan Next(int configuredSeconds, ILogger logger)
{
// Warn rather than clamp silently: an operator who deliberately set a
// large value and got a smaller one has config and behaviour disagreeing
// with no way to tell why. A negative value is a mistake too, so it is
// worth the same line.
if (configuredSeconds > MaxStartupJitterSeconds)
{
logger.LogWarning(
"startupjitterseconds {Configured} exceeds the {Max}s ceiling; using {Max}s",
configuredSeconds, MaxStartupJitterSeconds, MaxStartupJitterSeconds);
}
else if (configuredSeconds < 0)
{
logger.LogWarning(
"startupjitterseconds {Configured} is negative; startup jitter disabled",
configuredSeconds);
}
int spread = Math.Clamp(configuredSeconds, 0, MaxStartupJitterSeconds);
if (spread == 0)
return TimeSpan.Zero;
// Milliseconds, not whole seconds: 700 endpoints over a 30s window would
// otherwise land in 30 clumps of ~23 simultaneous arrivals, which is the
// same pile-up in miniature.
return TimeSpan.FromMilliseconds(Random.Shared.Next(0, spread * 1000));
}
}

View File

@@ -139,6 +139,25 @@ public sealed class TelemetryWorker : BackgroundService
"Endpoint agent {Version} -> {BaseUrl}, cadence {Cadence}s +/-{Jitter}s",
agentVersion, config.BaseUrl, config.CadenceSeconds, config.JitterSeconds);
// Spread first contact across the fleet. JitterSeconds only spreads the
// gap BETWEEN runs, so without this the whole fleet reports the instant
// its service starts. See StartupJitter.
var startupDelay = StartupJitter.Next(config.StartupJitterSeconds, logger);
if (startupDelay > TimeSpan.Zero)
{
logger.LogInformation(
"Delaying first telemetry report by {Delay}ms (startup jitter)",
(int)startupDelay.TotalMilliseconds);
try
{
await Task.Delay(startupDelay, stoppingToken);
}
catch (OperationCanceledException)
{
return;
}
}
bool firstRun = true;
while (!stoppingToken.IsCancellationRequested)
{

View File

@@ -346,7 +346,8 @@ static void RegisterCoreServices(IServiceCollection services, AgentConfig config
sp.GetRequiredService<CommandClient>(),
sp.GetRequiredService<CommandExecutor>(),
sp.GetRequiredService<ILogger<CommandWorker>>(),
sp.GetRequiredService<CollectSignal>()));
sp.GetRequiredService<CollectSignal>(),
config));
}
static void ConfigureLogging(ILoggingBuilder logging, string logDirectory)

View File

@@ -131,6 +131,27 @@
(AgentConfig.LaunchPaths, shipped defaults overridable per site).
1.1.0: generic, data-driven service_*/process_* actions carry their
target over the wire, so new policies/apps need no agent rebuild. -->
<!-- 1.12.0: startup jitter before first contact. Both loops previously made
their first request the instant the service started, and the service is
installed start=auto, so a patch reboot put the whole fleet on the wire
together - twice per machine (a telemetry report AND a command poll).
jitterseconds did not help: it spreads the gap BETWEEN runs, not first
contact. A 700-endpoint burst drove TLS handshakes to 1482ms worst case
and pinned CPU at 305% while the database sat idle at 3 active queries;
spreading the same arrivals over 30s cut worst-case handshake to 63.7ms
with no server-side change. New startupjitterseconds (default 30, 0
disables) is applied by StartupJitter.Next in both TelemetryWorker and
CommandWorker. Randomized in milliseconds rather than whole seconds
because a 30s window at second granularity re-clumps a large fleet into
30 buckets of simultaneous arrivals. Clamped to 300s and warned about
when out of range: the command channel is how an operator would correct
a bad value, so an unbounded delay would remove the means of recovery.
Costs up to startupjitterseconds of extra latency before a rebooted
endpoint picks up a queued command, on top of a reboot the machine was
already unreachable for. The once-only console switch bypasses the delay
entirely (it calls RunOnceAsync directly), so smoke tests stay instant.
appsettings schema gains a key; older packages without it get the
AgentConfig default. No tray change - tray stays 1.4.0. -->
<!-- 1.11.0: on-demand user-context refresh. "Refresh Status" (collect_now)
and the tray's "Send Status" re-sent whatever was already in the spool,
so a drive the operator had just unmapped kept reporting OK until the
@@ -150,7 +171,7 @@
member of that group, so Start-ScheduledTask returned access denied and
the task only ever ran on its own trigger. Requires tray 1.4.0 - the tray
is the side that listens, so an older tray simply never answers. -->
<Version>1.11.0</Version>
<Version>1.12.0</Version>
<InvariantGlobalization>true</InvariantGlobalization>
<RuntimeIdentifier>win-x64</RuntimeIdentifier>
<SelfContained>true</SelfContained>

View File

@@ -3,6 +3,7 @@
"apikey": "REPLACE_WITH_COLLECTOR_KEY",
"cadenceseconds": 900,
"jitterseconds": 60,
"startupjitterseconds": 30,
"adoptonfirstrun": true,
"utilitiespath": "",
"logpath": "",

View File

@@ -118,6 +118,7 @@ _BASE_APPSETTINGS = {
'apikey': 'REPLACE_WITH_COLLECTOR_KEY',
'cadenceseconds': 900,
'jitterseconds': 60,
'startupjitterseconds': 30,
'adoptonfirstrun': True,
'utilitiespath': '',
'logpath': '',