From 6937ff73b8fc13da26a246122b0a4f2f667d9f37 Mon Sep 17 00:00:00 2001 From: Oliver Kieselbach Date: Sat, 25 Apr 2026 22:06:42 +0200 Subject: [PATCH] fix(v2): start drain pump at Start() step 3b instead of after collector boot MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Symptom: Web UI showed register-session, then ~6.7s of silence, then a wall of ~100 events at once — visibly different from V1's streaming feel. Confirmed on session 3808befb-…: agent_started enqueued at 18:20:20.5, first BackendTelemetryUploader flush at 18:20:27.2 with firstId=0 lastId=99 (a full default 100-item batch). Root cause: the periodic drain pump was started at Start() step 15, after collector hosts had spun up. Steps 4-14 do meaningful synchronous work — gather-rule compile, Hello event-log subscriptions, PowerShell runspace open in DeliveryOptimizationCollector, ipinfo.io GeoLocation, analyzer scheduling — which on a constrained VM kept the calling thread (or the ThreadPool) busy for ~6.7s. During that window the spool accumulated 100 startup signals, saturating the batchSize cap. Even though immediate-flush wakeups did fire correctly, they only set a TaskCompletionSource that nobody was awaiting yet. Fix: move the drain pump start to step 3b, directly after the spool and the immediate-flush bridge are wired (step 3 + 3a). The pump's loop only references _spool / _transport (both built at step 3) and the wakeup TCS (step 3a) — no collector-state, classifier-state, or ingress dependency — so an early start is safe. An empty Peek returns OK(0) without an HTTP round-trip, so a pump tick that races ahead of any enqueue is a no-op. With the pump live from step 3b onward, the very first immediate-flush wakeup (e.g. agent_started in onIngressReady at step 13b) sets the TCS and the drain loop's WhenAny returns within milliseconds, then DrainAllAsync's peek-flush-peek loop drains whatever the spool has accumulated up to that moment in tight ~100-item batches. Tests: V2.Core 732/732 green; no behaviour-coupling on the old step 15 position. Solution build 0/0. Co-Authored-By: Claude Opus 4.7 (1M context) --- .../Orchestration/EnrollmentOrchestrator.cs | 32 ++++++++++++++++--- .../buildcounter.txt | 2 +- .../AutopilotMonitor.Agent/buildcounter.txt | 2 +- 3 files changed, 29 insertions(+), 7 deletions(-) diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/EnrollmentOrchestrator.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/EnrollmentOrchestrator.cs index c0d17ddf..edba4527 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/EnrollmentOrchestrator.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/EnrollmentOrchestrator.cs @@ -447,14 +447,36 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration // the spool for up to _drainInterval before the periodic loop uploads them, // producing the ~30 s "session-register then silence" gap at session start. // - // The signal TCS is installed BEFORE the subscription — and both BEFORE the drain - // task starts at step 15 — so any Enqueue fired during the rest of Start() (e.g. + // The signal TCS is installed BEFORE the subscription, and both BEFORE the drain + // task starts at step 3b — so any Enqueue fired during the rest of Start() (e.g. // the EspConfigDetected bootstrap at step 13c or the synchronous Classifier-Start // at step 11.5) sets the current signal rather than hitting a null field. _immediateFlushSignal = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); _immediateFlushBridge = OnImmediateFlushRequested; _spool.ImmediateFlushRequested += _immediateFlushBridge; + // 3b) Periodic drain pump (fire-and-forget). Started here — directly after the spool + // and the immediate-flush bridge are wired — instead of after collector startup, + // because steps 4-14 do non-trivial synchronous work (gather-rule compile, Hello + // event-log subscriptions, PowerShell runspace open in DeliveryOptimizationCollector, + // ipinfo.io GeoLocation, analyzer scheduling, …). On a constrained VM that whole + // stretch ran ~6.7 s in session 3808befb-…, during which 100 startup signals + // accumulated in the spool. The first batch then hit the upload right when the + // pump finally got a turn, surfacing in the Web UI as "session opens, silence, + // then a wall of 100 events" rather than the V1 streaming feel. + // + // With the pump live from step 3b onward, the very first immediate-flush wakeup + // (e.g. agent_started in onIngressReady at step 13b) sets the TCS and the drain + // loop's WhenAny returns within milliseconds, draining whatever the spool has + // accumulated up to that moment via DrainAllAsync's peek-flush-peek loop. + // + // Safety: the loop only references _spool and _transport (both built at step 3), + // and the wakeup TCS (this step). No collector-state, classifier-state, or + // ingress dependency. An empty Peek returns OK(0) without an HTTP round-trip, + // so a pump tick that races ahead of any enqueue is a no-op. + _drainCts = new CancellationTokenSource(); + _drainTask = Task.Run(() => DrainLoopAsync(_drainCts.Token)); + // 4) Event-Emitter-Kette. Single-rail (Plan §5.10): der TelemetryEventEmitter wird // lokal gebaut und nur in die zwei erlaubten Caller (EventTimelineEmitter, // BackPressureEventObserver) injiziert. Kein Feld mehr auf dem Orchestrator — @@ -680,9 +702,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration } } - // 15) Periodischer Drain-Loop (Fire-and-forget). - _drainCts = new CancellationTokenSource(); - _drainTask = Task.Run(() => DrainLoopAsync(_drainCts.Token)); + // 15) (moved) Periodic drain loop is now started at step 3b — directly after the + // spool / immediate-flush bridge are wired — so it does not have to wait for + // collector startup to finish. See the rationale at step 3b. // 16) Max-lifetime watchdog (M4.6.α). Fires once after the configured duration when // no real terminal stage has been reached. Timer is a best-effort System.Threading.Timer diff --git a/src/Agent/AutopilotMonitor.Agent.V2/buildcounter.txt b/src/Agent/AutopilotMonitor.Agent.V2/buildcounter.txt index 71627d71..aef2e272 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2/buildcounter.txt +++ b/src/Agent/AutopilotMonitor.Agent.V2/buildcounter.txt @@ -1 +1 @@ -348 +349 diff --git a/src/Agent/AutopilotMonitor.Agent/buildcounter.txt b/src/Agent/AutopilotMonitor.Agent/buildcounter.txt index ddbefde5..34684091 100644 --- a/src/Agent/AutopilotMonitor.Agent/buildcounter.txt +++ b/src/Agent/AutopilotMonitor.Agent/buildcounter.txt @@ -1 +1 @@ -1168 +1169