Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -270,7 +270,8 @@
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.
Expand Down Expand Up @@ -803,7 +804,8 @@
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;

Expand Down Expand Up @@ -4763,10 +4765,10 @@
/// <summary>The same reconstruction from a payload that came from somewhere other than the row — an offloaded one fetched back out of the artifact store.</summary>
private static AgentEvent ReplayedEvent(AgentEventKind kind, string? text, string? dataJson)
{
if (dataJson is not { Length: > 0 } json) return new AgentEvent { Kind = kind, Text = text };

Check warning on line 4768 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / recurring jobs fire (worker host · Postgres)

Possible null reference assignment.

Check warning on line 4768 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (E2ETests · HTTP · Postgres)

Possible null reference assignment.

Check warning on line 4768 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (UnitTests)

Possible null reference assignment.

Check warning on line 4768 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (UnitTests)

Possible null reference assignment.

Check warning on line 4768 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (IntegrationTests · Postgres)

Possible null reference assignment.

try { using var doc = JsonDocument.Parse(json); return new AgentEvent { Kind = kind, Text = text, Data = doc.RootElement.Clone() }; }

Check warning on line 4770 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / recurring jobs fire (worker host · Postgres)

Possible null reference assignment.

Check warning on line 4770 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (E2ETests · HTTP · Postgres)

Possible null reference assignment.

Check warning on line 4770 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (UnitTests)

Possible null reference assignment.

Check warning on line 4770 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (UnitTests)

Possible null reference assignment.

Check warning on line 4770 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (IntegrationTests · Postgres)

Possible null reference assignment.
catch (JsonException) { return new AgentEvent { Kind = kind, Text = text }; }

Check warning on line 4771 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / recurring jobs fire (worker host · Postgres)

Possible null reference assignment.

Check warning on line 4771 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (E2ETests · HTTP · Postgres)

Possible null reference assignment.

Check warning on line 4771 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (UnitTests)

Possible null reference assignment.

Check warning on line 4771 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (UnitTests)

Possible null reference assignment.

Check warning on line 4771 in backend/src/CodeSpace.Core/Services/Agents/AgentRunExecutor.cs

View workflow job for this annotation

GitHub Actions / dotnet test (IntegrationTests · Postgres)

Possible null reference assignment.
}

/// <summary>Ask the row, on a token of its own, whether the run actually reached a terminal state — the only honest answer to "did the landing take?" once an exception has been raised somewhere after the fenced write.</summary>
Expand Down
17 changes: 11 additions & 6 deletions backend/src/CodeSpace.Core/Services/Agents/HeartbeatLoop.cs
Original file line number Diff line number Diff line change
Expand Up @@ -17,18 +17,23 @@ public static class HeartbeatLoop
/// The first ping is deferred by one interval because the claim already stamped an initial heartbeat.
///
/// <para><paramref name="timeProvider"/> exists so the cadence can be driven deterministically in a test instead
/// of raced against the wall clock. It is OPTIONAL and defaults to <see cref="TimeProvider.System"/>, so every
/// existing call site compiles unchanged and production behaviour is byte-identical — the system provider's
/// <c>Delay</c> IS the <c>Task.Delay</c> this used before. <see cref="TimeProvider"/> 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.</para>
/// of raced against the wall clock. Production passes the DI-registered <see cref="TimeProvider.System"/>, whose
/// <c>Delay</c> IS the <c>Task.Delay</c> this used before, so production behaviour is byte-identical.
/// <see cref="TimeProvider"/> 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.</para>
///
/// <para>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.</para>
/// </summary>
public static async Task RunAsync(Func<CancellationToken, Task> ping, TimeSpan interval, Action<Exception> onPingError, CancellationToken cancellationToken, TimeProvider? timeProvider = null)
public static async Task RunAsync(Func<CancellationToken, Task> ping, TimeSpan interval, Action<Exception> 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
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -109,7 +109,7 @@ internal static bool MeetsCase(CriticVerdict verdict, bool flawed, string auditT
{
using var scope = _fixture.BeginScope();
await scope.Resolve<IAgentRunService>().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
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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()
{
Expand Down
62 changes: 46 additions & 16 deletions backend/tests/CodeSpace.UnitTests/Workflows/HeartbeatLoopTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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).
///
/// <para>The cadence is driven by a <see cref="FakeTimeProvider"/>, 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
/// <para>Every cadence here is driven by a <see cref="FakeTimeProvider"/>, 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 (<c>pings should be
/// &gt;= 2 but was 1</c>), 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.</para>
/// 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.</para>
/// </summary>
[Trait("Category", "Unit")]
public class HeartbeatLoopTests
Expand Down Expand Up @@ -51,20 +53,20 @@ public async Task Pings_once_per_interval_until_cancelled()
}

/// <summary>
/// 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 <paramref name="ticked"/>, rather than advancing once and
/// assuming it was listening.
///
/// <para>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
/// clock then never moves again and the wait burns its full timeout. That is the race this test
/// 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.</para>
/// </summary>
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);
}
Expand All @@ -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();
Expand All @@ -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
}

/// <summary>
/// The clock is a REQUIRED parameter, so no call site can fall back to the wall clock by saying nothing.
///
/// <para>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.</para>
/// </summary>
[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");
}
}
Loading