diff --git a/backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs b/backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs index 4642d811e..b5c50ce85 100644 --- a/backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs +++ b/backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs @@ -270,7 +270,8 @@ public async Task ExecuteAsync(Guid agentRunId, CancellationToken cancellationTo ct => RenewObservationAndCredentialAsync(heartbeatRuns, owner, observerCts, ct), AgentRunLiveness.HeartbeatInterval, ex => _logger.LogWarning(ex, "Heartbeat ping failed for agent run {RunId}; lost ownership stops observation, transient failures retry", agentRunId), - heartbeatCts.Token); + heartbeatCts.Token, + _clock); // Holds the run's resolved secret(s) once the credential is resolved (below), so the catch-all can scrub // them from a failure message too. None until then — a pre-resolve failure has no secret to leak. @@ -803,7 +804,8 @@ public async Task ReattachAsync(AgentRunReattachReservation reservation, Cancell ct => RenewObservationAndCredentialAsync(heartbeatRuns, owner, observerCts, ct), AgentRunLiveness.HeartbeatInterval, ex => _logger.LogWarning(ex, "Heartbeat ping failed for re-attached agent run {RunId}; lost ownership stops observation, transient failures retry", agentRunId), - heartbeatCts.Token); + heartbeatCts.Token, + _clock); var expectedEpoch = owner.Epoch; diff --git a/backend/src/CodeSpace.Core/Services/Agents/HeartbeatLoop.cs b/backend/src/CodeSpace.Core/Services/Agents/HeartbeatLoop.cs index 4bfb64882..dc61e8271 100644 --- a/backend/src/CodeSpace.Core/Services/Agents/HeartbeatLoop.cs +++ b/backend/src/CodeSpace.Core/Services/Agents/HeartbeatLoop.cs @@ -17,18 +17,23 @@ public static class HeartbeatLoop /// The first ping is deferred by one interval because the claim already stamped an initial heartbeat. /// /// exists so the cadence can be driven deterministically in a test instead - /// of raced against the wall clock. It is OPTIONAL and defaults to , so every - /// existing call site compiles unchanged and production behaviour is byte-identical — the system provider's - /// Delay IS the Task.Delay this used before. rather than a bespoke clock - /// interface: it is the BCL's own seam, so the next thing that needs one does not invent a second vocabulary. + /// of raced against the wall clock. Production passes the DI-registered , whose + /// Delay IS the Task.Delay this used before, so production behaviour is byte-identical. + /// rather than a bespoke clock interface: it is the BCL's own seam, so the next thing + /// that needs one does not invent a second vocabulary. + /// + /// REQUIRED, not optional-defaulting-to-System. While it defaulted, BOTH executor call sites silently kept + /// the wall clock: the seam existed and nothing used it, so a test could only pin the loop by racing real + /// milliseconds. A required parameter makes "which clock does this run on" a decision the compiler asks at every + /// call site instead of one a default answers invisibly. /// - public static async Task RunAsync(Func ping, TimeSpan interval, Action onPingError, CancellationToken cancellationToken, TimeProvider? timeProvider = null) + public static async Task RunAsync(Func ping, TimeSpan interval, Action onPingError, CancellationToken cancellationToken, TimeProvider timeProvider) { try { while (!cancellationToken.IsCancellationRequested) { - await Task.Delay(interval, timeProvider ?? TimeProvider.System, cancellationToken).ConfigureAwait(false); + await Task.Delay(interval, timeProvider, cancellationToken).ConfigureAwait(false); try { diff --git a/backend/tests/CodeSpace.E2ETests/Workflows/RealModelAnswerReviewDelegationE2ETests.cs b/backend/tests/CodeSpace.E2ETests/Workflows/RealModelAnswerReviewDelegationE2ETests.cs index 594e58063..dbe8ef5c7 100644 --- a/backend/tests/CodeSpace.E2ETests/Workflows/RealModelAnswerReviewDelegationE2ETests.cs +++ b/backend/tests/CodeSpace.E2ETests/Workflows/RealModelAnswerReviewDelegationE2ETests.cs @@ -109,7 +109,7 @@ internal static bool MeetsCase(CriticVerdict verdict, bool flawed, string auditT { using var scope = _fixture.BeginScope(); await scope.Resolve().HeartbeatAsync(owner, cancellationToken); - }, TimeSpan.FromSeconds(5), error => { Interlocked.CompareExchange(ref heartbeatFailure, error, null); deadline.Cancel(); }, heartbeatCancellation.Token); + }, TimeSpan.FromSeconds(5), error => { Interlocked.CompareExchange(ref heartbeatFailure, error, null); deadline.Cancel(); }, heartbeatCancellation.Token, TimeProvider.System); try { diff --git a/backend/tests/CodeSpace.UnitTests/Workflows/AgentRunLivenessTests.cs b/backend/tests/CodeSpace.UnitTests/Workflows/AgentRunLivenessTests.cs index 3572f6403..986b8f71d 100644 --- a/backend/tests/CodeSpace.UnitTests/Workflows/AgentRunLivenessTests.cs +++ b/backend/tests/CodeSpace.UnitTests/Workflows/AgentRunLivenessTests.cs @@ -58,6 +58,18 @@ public void HeartbeatInterval_is_floored_for_a_tiny_window() AgentRunLiveness.HeartbeatInterval.ShouldBe(TimeSpan.FromSeconds(5)); } + [Fact] + public void HeartbeatInterval_defaults_to_one_hundred_seconds() + { + // The cadence a live agent run actually pings at — and the ONLY place it is pinned as a number, now that + // HeartbeatLoopTests drives a fake clock. A fake clock proves the loop honours whatever interval it is + // handed; it says nothing about which interval production hands it. Changing either half of the + // derivation (the 5-minute default window, or the /3) silently re-cadences every run, and reds here. + Environment.SetEnvironmentVariable(AgentRunLiveness.WindowEnvVar, null); + + AgentRunLiveness.HeartbeatInterval.ShouldBe(TimeSpan.FromSeconds(100)); + } + [Fact] public void HeartbeatInterval_stays_below_the_window_at_the_default() { diff --git a/backend/tests/CodeSpace.UnitTests/Workflows/HeartbeatLoopTests.cs b/backend/tests/CodeSpace.UnitTests/Workflows/HeartbeatLoopTests.cs index bba90af15..c13c95374 100644 --- a/backend/tests/CodeSpace.UnitTests/Workflows/HeartbeatLoopTests.cs +++ b/backend/tests/CodeSpace.UnitTests/Workflows/HeartbeatLoopTests.cs @@ -9,11 +9,13 @@ namespace CodeSpace.UnitTests.Workflows; /// cadence, a failed ping is reported but doesn't kill the loop, and it returns cleanly on cancellation /// (never surfacing OperationCanceledException). /// -/// The cadence is driven by a , not by the wall clock. The first of these tests -/// asserted on how many real 20ms ticks fitted inside a real 200ms window, and reddened at random on a loaded -/// runner — observed on PR #1297, a diff that touched neither this loop nor anything near it. A test that reds at +/// Every cadence here is driven by a , not by the wall clock. Both counting +/// tests below once asserted on how many real 20ms ticks fitted inside a real 200ms window, and each reddened at +/// random on a loaded runner — the ping test on PR #1297, the failing-ping test on #2001 (pings should be +/// >= 2 but was 1), both diffs that touched neither this loop nor anything near it. A test that reds at /// random is worse than a missing one: it teaches every reader to re-run red instead of reading it, which is how a -/// real regression gets waved through. Advancing a fake clock makes the SAME property exact instead of probable. +/// real regression gets waved through. Advancing a fake clock makes the SAME property exact instead of probable — +/// and turns "at least 2 pings" into "exactly one per elapsed interval", which is the property that was meant. /// [Trait("Category", "Unit")] public class HeartbeatLoopTests @@ -51,8 +53,8 @@ public async Task Pings_once_per_interval_until_cancelled() } /// - /// Advances the fake clock until the loop pings, rather than advancing once and assuming it was - /// listening. + /// Advances the fake clock until the loop signals , rather than advancing once and + /// assuming it was listening. /// /// The loop arms its next timer inside Task.Delay AFTER the previous ping returns, so a /// single Advance can land in the window before that registration and be missed entirely — the @@ -60,11 +62,11 @@ public async Task Pings_once_per_interval_until_cancelled() /// kept losing. Nudging in fractions of an interval cannot fire a timer early, and the count /// assertion at the call site is what still proves one ping per interval. /// - private static async Task AdvanceUntilPingedAsync(FakeTimeProvider time, SemaphoreSlim pinged, TimeSpan interval, int ordinal) + private static async Task AdvanceUntilPingedAsync(FakeTimeProvider time, SemaphoreSlim ticked, TimeSpan interval, int ordinal) { for (var nudge = 0; nudge < 200; nudge++) { - if (await pinged.WaitAsync(TimeSpan.FromMilliseconds(10))) return; + if (await ticked.WaitAsync(TimeSpan.FromMilliseconds(10))) return; time.Advance(interval / 10); } @@ -75,26 +77,38 @@ private static async Task AdvanceUntilPingedAsync(FakeTimeProvider time, Semapho [Fact] public async Task A_failing_ping_is_reported_but_does_not_kill_the_loop() { + var time = new FakeTimeProvider(); + var interval = TimeSpan.FromSeconds(30); + var reported = new SemaphoreSlim(0); var pings = 0; var errors = 0; using var cts = new CancellationTokenSource(); + // The semaphore is released from onPingError, not from the ping: by the time it signals, BOTH counters + // for that tick have settled, so the assertions below read a consistent pair rather than a half-applied one. var loop = HeartbeatLoop.RunAsync( _ => { Interlocked.Increment(ref pings); throw new InvalidOperationException("transient db blip"); }, - TimeSpan.FromMilliseconds(20), - _ => Interlocked.Increment(ref errors), - cts.Token); + interval, + _ => { Interlocked.Increment(ref errors); reported.Release(); }, + cts.Token, + time); - cts.CancelAfter(TimeSpan.FromMilliseconds(200)); - await loop; + for (var i = 1; i <= 3; i++) + { + await AdvanceUntilPingedAsync(time, reported, interval, i); + + Volatile.Read(ref pings).ShouldBe(i, "a throwing ping must not stop, skip, or double the cadence"); + Volatile.Read(ref errors).ShouldBe(i, "every failed ping is reported exactly once — none aborted the loop"); + } - pings.ShouldBeGreaterThanOrEqualTo(2); - errors.ShouldBe(pings); // every failed ping was reported; none aborted the loop + cts.Cancel(); + await loop; // a loop whose every ping threw still returns cleanly on cancel, never surfacing the failure } [Fact] public async Task Returns_without_pinging_when_already_cancelled() { + var time = new FakeTimeProvider(); var count = 0; using var cts = new CancellationTokenSource(); cts.Cancel(); @@ -103,8 +117,24 @@ await HeartbeatLoop.RunAsync( _ => { Interlocked.Increment(ref count); return Task.CompletedTask; }, TimeSpan.FromSeconds(30), _ => { }, - cts.Token); + cts.Token, + time); count.ShouldBe(0); // first ping is deferred one interval; cancelled before it } + + /// + /// The clock is a REQUIRED parameter, so no call site can fall back to the wall clock by saying nothing. + /// + /// It was optional-defaulting-to-System first, and both executor call sites took that default — the seam + /// existed and production ignored it, which is exactly how a "we made it testable" claim goes stale. A default + /// here is re-addable in one character and would red nothing else, so this pins the absence of one. + /// + [Fact] + public void The_clock_cannot_be_omitted_by_a_call_site() + { + var clock = typeof(HeartbeatLoop).GetMethod(nameof(HeartbeatLoop.RunAsync))!.GetParameters().Single(p => p.ParameterType == typeof(TimeProvider)); + + clock.HasDefaultValue.ShouldBeFalse("an optional clock is how both production heartbeats silently stayed on the wall clock"); + } }