diff --git a/backend/src/CodeSpace.Core/Services/Agents/AgentRetryContinuity.cs b/backend/src/CodeSpace.Core/Services/Agents/AgentRetryContinuity.cs index 255c1cc01..72b73c1e8 100644 --- a/backend/src/CodeSpace.Core/Services/Agents/AgentRetryContinuity.cs +++ b/backend/src/CodeSpace.Core/Services/Agents/AgentRetryContinuity.cs @@ -11,7 +11,7 @@ namespace CodeSpace.Core.Services.Agents; public static class AgentRetryContinuity { /// The honest-redo line: fires ONLY when a resumed conversation exists but the workspace was NOT pinned to a prior pushed branch — never on a genuine cold-start retry (no prior attempt at all), which stays byte-identical. - public const string HonestNoContinuityHint = "Note: your prior attempt's conversation is restored, but its git changes were NOT preserved in this workspace (no pushed branch was found to continue from) — you must redo any relevant file changes from scratch."; + public const string HonestNoContinuityHint = "Note: your prior attempt's conversation is restored, but its git changes were NOT preserved in this workspace (your prior attempt pushed no branch of its own) — you must redo any relevant file changes from scratch."; /// Append to a resumed task's goal. One composition, so the two lanes cannot drift on the separator either. public static string WithHonestNoContinuityHint(string goal) => $"{goal}\n\n{HonestNoContinuityHint}"; @@ -19,17 +19,17 @@ public static class AgentRetryContinuity /// /// 3c: what a CROSS-HOST continuation is told, and the reason it needs its own sentence. The two lanes above /// retry an attempt that FINISHED on a live host, so their only open question is whether a branch was pushed. - /// This lane continues an attempt whose machine was lost mid-run: the conversation comes from a checkpoint taken - /// some time before the loss, and the working tree is simply gone. Both halves have to be said, because the - /// restored transcript will describe edits — possibly edits made after the checkpoint — that the new workspace - /// does not contain, and an agent that is not told will read its own transcript as evidence about files it cannot - /// see. + /// This lane continues an attempt whose machine or process was lost mid-run: the conversation comes from a + /// checkpoint taken some time before the loss, and the working tree is simply gone. Both halves have to be said, + /// because the restored transcript will describe edits — possibly edits made after the checkpoint — that the new + /// workspace does not contain, and an agent that is not told will read its own transcript as evidence about files + /// it cannot see. /// - public const string LostHostPreamble = "Note: the machine running your previous attempt was lost mid-run. Your conversation is restored from a checkpoint taken before that, so it may describe work you did after the checkpoint, and it may be missing your last few turns."; + public const string LostHostPreamble = "Note: the machine or the process running your previous attempt was lost mid-run. Your conversation is restored from a checkpoint taken before that, so it may describe work you did after the checkpoint, and it may be missing your last few turns."; /// Said when the lost attempt HAD published a branch: the workspace is checked out at it, so the published work is present and only the unpublished remainder is gone. Takes the branch name so the agent can verify rather than take the claim on trust. public static string LostHostPublishedBranchHint(string branch) => - $"Your previous attempt published branch `{branch}`, and this workspace is checked out AT that branch — that work is here. Anything you had NOT published to it died with the machine, so check the files before continuing and redo whatever is missing."; + $"Your previous attempt published branch `{branch}`, and this workspace is checked out AT that branch — that work is here. Anything you had NOT published to it was lost with that attempt, so check the files before continuing and redo whatever is missing."; /// /// Append the cross-host continuation's honesty block to a resumed task's goal: the preamble always, then what @@ -49,8 +49,8 @@ public static string WithLostHostHint(string goal, string? publishedBranch, bool /// /// 3c: said when the lost host's checkpoint could not be READ — reaped, or its storage unreachable. The attempt /// still runs (failing it would spend the retry this whole path exists to improve), but it runs COLD, and an - /// agent that was going to be handed a conversation must be told it is not getting one. Appended to the - /// lost-host block rather than replacing it: the machine really was lost, which is still the reason. + /// agent that was going to be handed a conversation must be told it is not getting one. Appended to the lost-host + /// block rather than replacing it: the machine or the process really was lost, which is still the reason. /// public const string LostHostCheckpointUnreadableHint = "Your previous conversation could not be recovered either — the checkpoint it was stored in is no longer readable — so you are starting this task from the beginning."; diff --git a/backend/src/CodeSpace.Core/Services/Agents/AgentRunService.cs b/backend/src/CodeSpace.Core/Services/Agents/AgentRunService.cs index 85f729eac..f81faa16c 100644 --- a/backend/src/CodeSpace.Core/Services/Agents/AgentRunService.cs +++ b/backend/src/CodeSpace.Core/Services/Agents/AgentRunService.cs @@ -777,7 +777,8 @@ public async Task CancelRunningAsync(Guid runId, string reason, AgentRunAb // 3c: a deliberate cancel is a CLEAN landing, so it releases the mid-run session checkpoint exactly as // completion does. Nobody owes this run a continuation, and a kept reference would pin the artifact // Referenced (terminal in the retention ledger) for good — and make a later retry of the same subtask read - // the cancel as a host loss. Only the reconciler's abandon keeps these columns. + // the cancel as a host loss. Only an abandon-class ending keeps these columns: the reconciler's abandon, or + // its spool recovery. var cancelled = await _db.AgentRun .Where(r => r.Id == runId && r.Status == AgentRunStatus.Running && r.FenceEpoch == snapshot.FenceEpoch) .ExecuteUpdateAsync(s => s @@ -976,8 +977,8 @@ await _db.AgentRun.AsNoTracking().SingleOrDefaultAsync(r => r.Id == runId, cance // 3c: a prior attempt whose HOST died has no result at all — the reconciler's abandon writes none — so // the captured-transcript read above finds nothing for exactly the population a warm retry helps most. // Its mid-run checkpoint is what survives, and a TERMINAL row still naming one is the signature of an - // abandon: every clean landing — completion or cancel — releases these two columns in its own terminal - // write; only an abandon keeps them. + // abandon-class ending: every clean landing — completion or cancel — releases these two columns in its own + // terminal write; only the reconciler's abandon, or its spool recovery, keeps them. if (TryResumableFromCheckpoint(candidate.Id, candidate.Status, candidate.SessionId, candidate.SessionTranscriptCheckpointArtifactId, candidate.SessionTranscriptCheckpointAt) is { } continued) return continued; } diff --git a/backend/src/CodeSpace.Core/Services/Agents/Credentials/Broker/LoopbackModelCredentialBroker.cs b/backend/src/CodeSpace.Core/Services/Agents/Credentials/Broker/LoopbackModelCredentialBroker.cs index cccdf5e6b..fd21c221c 100644 --- a/backend/src/CodeSpace.Core/Services/Agents/Credentials/Broker/LoopbackModelCredentialBroker.cs +++ b/backend/src/CodeSpace.Core/Services/Agents/Credentials/Broker/LoopbackModelCredentialBroker.cs @@ -267,7 +267,11 @@ private Lease Install(Lease lease, TimeSpan ttl) if (superseded is not null) CloseQuietly(superseded.Listener); - _ = Task.Run(() => AcceptAsync(lease), CancellationToken.None); + // CALLED, not handed to Task.Run: an async method runs synchronously up to its first await, so the loop's first + // wait is registered on the listener before this returns. The managed HttpListener fails only the waits it + // already holds when it closes; a close that lands while a pool thread is still registering the first one is + // never delivered, and that loop then waits for the life of the worker on a listener that no longer exists. + _ = AcceptAsync(lease); return lease; } diff --git a/backend/src/CodeSpace.Core/Services/Supervisor/SupervisorTurnService.Rehydrate.cs b/backend/src/CodeSpace.Core/Services/Supervisor/SupervisorTurnService.Rehydrate.cs index 357579870..4977ef974 100644 --- a/backend/src/CodeSpace.Core/Services/Supervisor/SupervisorTurnService.Rehydrate.cs +++ b/backend/src/CodeSpace.Core/Services/Supervisor/SupervisorTurnService.Rehydrate.cs @@ -642,7 +642,7 @@ private async Task FoldAcceptanceGradeAsync(SupervisorP // without a pulse the reconciler reads a genuinely-alive resolve grade as abandoned and re-dispatches // the run mid-grade. Starts only when a real grade fires (every early return above skips it). using var heartbeatCts = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); - var heartbeat = RunGradingHeartbeatLoopAsync(supervisorRunId, nodeId, SupervisorLane.AcceptanceGradeHeartbeatInterval, heartbeatCts.Token, "Supervisor resolve acceptance grading is still in progress."); + var heartbeat = RunGradingHeartbeatLoopAsync(supervisorRunId, nodeId, SupervisorLane.AcceptanceGradeHeartbeatInterval, heartbeatCts.Token, TimeProvider.System, "Supervisor resolve acceptance grading is still in progress."); BenchmarkGrade grade; try @@ -762,7 +762,7 @@ private async Task FoldUnitAcceptanceGradeAsync(Supervi // reconciler reads this genuinely-alive fold as abandoned and re-dispatches the run mid-grade (the S3 // adversarial scan's M4: the baseline roughly doubled the silent window). using var heartbeatCts = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); - var heartbeat = RunGradingHeartbeatLoopAsync(supervisorRunId, nodeId, SupervisorLane.AcceptanceGradeHeartbeatInterval, heartbeatCts.Token, "Supervisor per-unit acceptance grading is still in progress."); + var heartbeat = RunGradingHeartbeatLoopAsync(supervisorRunId, nodeId, SupervisorLane.AcceptanceGradeHeartbeatInterval, heartbeatCts.Token, TimeProvider.System, "Supervisor per-unit acceptance grading is still in progress."); try { @@ -1552,7 +1552,7 @@ private static IReadOnlyList BranchlessUnits(SupervisorTu private async Task GradeStopTargetsWithHeartbeatAsync(Guid supervisorRunId, string nodeId, Guid teamId, IReadOnlyList<(Guid RepositoryId, string Alias, string Branch)> targets, IReadOnlyList<(string Label, SupervisorAcceptanceSpec? Spec)> gates, IReadOnlyDictionary oracleBaseShas, IReadOnlyList oracleFloorPrograms, CancellationToken cancellationToken) { using var heartbeatCts = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); - var heartbeat = RunGradingHeartbeatLoopAsync(supervisorRunId, nodeId, SupervisorLane.AcceptanceGradeHeartbeatInterval, heartbeatCts.Token); + var heartbeat = RunGradingHeartbeatLoopAsync(supervisorRunId, nodeId, SupervisorLane.AcceptanceGradeHeartbeatInterval, heartbeatCts.Token, TimeProvider.System); try { @@ -1567,14 +1567,14 @@ private async Task GradeStopTargetsWithHeartbeatAsync(Guid super } } - /// The heartbeat loop itself: sleeps, logs, repeats — until fires (grading finished). A cancellation mid-sleep is the expected exit, never propagated as a fault. Internal + interval-parameterized so a unit test can pin the cancellation contract with a millisecond-scale interval instead of waiting out the real 90s production value. - internal async Task RunGradingHeartbeatLoopAsync(Guid supervisorRunId, string nodeId, TimeSpan interval, CancellationToken cancellationToken, string message = "Supervisor stop acceptance grading is still in progress.") + /// The heartbeat loop itself: sleeps, logs, repeats — until fires (grading finished). A cancellation mid-sleep is the expected exit, never propagated as a fault. Internal + clock-parameterized so a unit test drives the sleep on a fake instead of racing the wall clock; REQUIRED rather than defaulting to the system clock for the reason gives — a default is how a call site keeps the wall clock without saying so. + internal async Task RunGradingHeartbeatLoopAsync(Guid supervisorRunId, string nodeId, TimeSpan interval, CancellationToken cancellationToken, TimeProvider timeProvider, string message = "Supervisor stop acceptance grading is still in progress.") { try { while (true) { - await Task.Delay(interval, cancellationToken).ConfigureAwait(false); + await Task.Delay(interval, timeProvider, cancellationToken).ConfigureAwait(false); await _recordLogger.LogAsync(supervisorRunId, nodeId, Workflows.Lifecycle.LogLevel.Info, message, cancellationToken).ConfigureAwait(false); diff --git a/backend/src/CodeSpace.Core/Services/Workflows/Artifacts/Retention/ArtifactRetentionPolicy.cs b/backend/src/CodeSpace.Core/Services/Workflows/Artifacts/Retention/ArtifactRetentionPolicy.cs index 823fa0419..5f6df4193 100644 --- a/backend/src/CodeSpace.Core/Services/Workflows/Artifacts/Retention/ArtifactRetentionPolicy.cs +++ b/backend/src/CodeSpace.Core/Services/Workflows/Artifacts/Retention/ArtifactRetentionPolicy.cs @@ -42,9 +42,10 @@ public static class ArtifactRetentionPolicy /// A mid-run session-transcript checkpoint. TWO HOURS, not seven days, and the short floor is the whole reason /// the class exists: a run writes one of these per minute, each supersedes the last, and a clean landing /// (completion or a deliberate cancel) clears the column that references the survivor — so on the seven-day floor - /// a single long run would hold every superseded copy of a growing transcript for over a week. An abandon keeps - /// the column on purpose, and that survivor is then Referenced for good; this floor does not collect it. Two hours still sits far outside the window in which - /// the reference lands (the stamp is the next statement after the write) and far outside the window in which a + /// a single long run would hold every superseded copy of a growing transcript for over a week. An abandon-class + /// ending (the reconciler's abandon, or its spool recovery) keeps the column on purpose, and that survivor is then + /// Referenced for good; this floor does not collect it. Two hours still sits far outside the window in which the + /// reference lands (the stamp is the next statement after the write) and far outside the window in which a /// continuation reads it (an abandon follows the host's death within one liveness window), so the floor costs /// nothing it protects. The quarantine stays the standard 24 h: the second, independent wait is unchanged. /// diff --git a/backend/tests/CodeSpace.IntegrationTests/Workflows/AgentNodeFlowTests.cs b/backend/tests/CodeSpace.IntegrationTests/Workflows/AgentNodeFlowTests.cs index 9fe5357b5..61d41ca07 100644 --- a/backend/tests/CodeSpace.IntegrationTests/Workflows/AgentNodeFlowTests.cs +++ b/backend/tests/CodeSpace.IntegrationTests/Workflows/AgentNodeFlowTests.cs @@ -808,7 +808,7 @@ public async Task A_retried_agent_node_restores_the_lost_hosts_checkpoint() resumed.ResumedFromCheckpointAt.ShouldNotBeNull("the launch stamps this onto the run's permanent confinement record"); resumed.ResumedFromAgentRunId.ShouldBe(lostAgent, "which attempt took over from which is a column, not prose"); retry.ResumedFromAgentRunId.ShouldBe(lostAgent, "and the task's provenance is promoted onto the row, like AgentDefinitionId"); - resumed.Goal.ShouldContain("machine running your previous attempt was lost", Case.Sensitive, + resumed.Goal.ShouldContain("the machine or the process running your previous attempt was lost", Case.Sensitive, "a restored conversation describes a working tree this sandbox does not have, and the agent must be told rather than left to infer it"); } finally @@ -850,7 +850,7 @@ public async Task A_host_loss_with_no_checkpoint_is_retried_cold_and_claims_noth resumed.ResumedFromCheckpointAt.ShouldBeNull(); resumed.ResumedFromAgentRunId.ShouldBeNull(); retry.ResumedFromAgentRunId.ShouldBeNull(); - resumed.Goal.ShouldNotContain("machine running your previous attempt was lost", Case.Sensitive, "nothing may assert a restored conversation this attempt does not have"); + resumed.Goal.ShouldNotContain("the machine or the process running your previous attempt was lost", Case.Sensitive, "nothing may assert a restored conversation this attempt does not have"); } finally { diff --git a/backend/tests/CodeSpace.UnitTests/Agents/ModelCredentialBrokerTests.cs b/backend/tests/CodeSpace.UnitTests/Agents/ModelCredentialBrokerTests.cs index b8638d4ce..6a7431019 100644 --- a/backend/tests/CodeSpace.UnitTests/Agents/ModelCredentialBrokerTests.cs +++ b/backend/tests/CodeSpace.UnitTests/Agents/ModelCredentialBrokerTests.cs @@ -520,11 +520,17 @@ public async Task A_lease_whose_listener_died_stops_being_claimed() broker.HasLease(runId).ShouldBeTrue("precondition: the lease is live and its listener is accepting"); + while (logger.Warned.Wait(0)) { } // whatever the open itself warned about is not the signal awaited below + // The platform failed the accept — a listener closed under us, an error nobody enumerated. The lease is still // in the table and still inside its window, so nothing about TIME will correct it. broker.BreakListenerForTest(runId); - await WaitUntilAsync(() => !broker.HasLease(runId), TimeSpan.FromSeconds(10), + // Woken by the drop's LAST effect rather than by polling HasLease: the warning is written only after the lease + // has left the table, so once it lands both assertions below read a finished drop instead of racing one. + (await logger.Warned.WaitAsync(TimeSpan.FromSeconds(10))).ShouldBeTrue("the accept loop never reported its dead listener within 10s — the close never reached a loop still registering its first wait, or the failure was swallowed without a word"); + + broker.HasLease(runId).ShouldBeFalse( "a lease whose accept loop has stopped went on reporting itself live. That is the worst answer this class can give: the child's connections sit unaccepted in a backlog instead of being refused, and a re-attach reading HasLease true concludes the run still has model access — so it lands no verdict and leaves the run Running, with no model and no explanation, for as long as the worker lives"); logger.Warnings.ShouldContain(line => line.Contains(runId.ToString(), StringComparison.Ordinal), @@ -575,7 +581,7 @@ public void A_rebind_is_only_built_for_a_handle_whose_agent_this_host_can_reach( } /// Stands in for this worker's own host identity inside [InlineData], which cannot carry a runtime value. - private const string ThisHost = "this-host"; + private const string ThisHost = "\0this-host"; /// The re-bind a later worker would build from what a run's durable handle carries — the point being that every value comes from , because a re-bind restores an address and never mints one. private static ModelCredentialRebindRequest RebindOf(BrokeredModelCredential brokered, Guid runId, long epoch) => new() @@ -654,12 +660,18 @@ private sealed class CapturingLogger : Microsoft.Extensions.Logging.ILogger Warnings { get; } = []; + /// Released AFTER each warning is recorded, so a waiter that acquires it reads a that already holds that line. + public SemaphoreSlim Warned { get; } = new(0); + public IDisposable BeginScope(TState state) where TState : notnull => NullScope.Instance; public bool IsEnabled(Microsoft.Extensions.Logging.LogLevel logLevel) => true; public void Log(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId, TState state, Exception? exception, Func formatter) { - if (logLevel >= Microsoft.Extensions.Logging.LogLevel.Warning) Warnings.Add(formatter(state, exception)); + if (logLevel < Microsoft.Extensions.Logging.LogLevel.Warning) return; + + Warnings.Add(formatter(state, exception)); + Warned.Release(); } private sealed class NullScope : IDisposable { public static readonly NullScope Instance = new(); public void Dispose() { } } diff --git a/backend/tests/CodeSpace.UnitTests/Supervisor/SupervisorGradingHeartbeatTests.cs b/backend/tests/CodeSpace.UnitTests/Supervisor/SupervisorGradingHeartbeatTests.cs index bed85387e..01833779c 100644 --- a/backend/tests/CodeSpace.UnitTests/Supervisor/SupervisorGradingHeartbeatTests.cs +++ b/backend/tests/CodeSpace.UnitTests/Supervisor/SupervisorGradingHeartbeatTests.cs @@ -1,6 +1,7 @@ using CodeSpace.Core.Services.Supervisor; using CodeSpace.Core.Services.Workflows.Lifecycle; using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Time.Testing; using Shouldly; using System.Text.Json; @@ -9,10 +10,15 @@ namespace CodeSpace.UnitTests.Supervisor; /// /// 🟢 Unit: the P1.3 grading-heartbeat loop () — /// pins the cancellation contract that keeps a long acceptance grade from looking abandoned to the reconciler -/// WITHOUT waiting out the real 90s production interval (a millisecond-scale interval drives the same code path). -/// The DB-observable effect (a real ledger row landing, and the reconciler reading it as liveness) is proved at -/// the integration tier — this pins the pure loop mechanics: it logs repeatedly while un-cancelled, stops the -/// instant it's cancelled (mid-sleep or between ticks), and never lets OperationCanceledException escape. +/// WITHOUT waiting out the real 90s production interval: a decides when each interval +/// has elapsed, so the production value itself costs nothing. The DB-observable effect (a real ledger row landing, +/// and the reconciler reading it as liveness) is proved at the integration tier — this pins the pure loop mechanics: +/// it logs once per elapsed interval while un-cancelled, stops the instant it's cancelled (mid-sleep or between +/// ticks), and never lets OperationCanceledException escape. +/// +/// These once slept on the wall clock — "three 15ms ticks within 10s", "cancel after 30ms" — which proved the +/// loop repeats only as reliably as the runner happened to schedule it. On the fake clock the same properties are +/// exact: one heartbeat per interval, not "at least three". /// [Trait("Category", "Unit")] public class SupervisorGradingHeartbeatTests @@ -27,41 +33,58 @@ private static SupervisorTurnService Service(IRunRecordLogger logger) => new(null!, null!, null!, db: Infrastructure.EmptyTestDb.New(), null!, null!, null!, null!, null!, logger, null!, null!, null!, new NullCompletionComposer(), null!, null!, NullLogger.Instance); [Fact] - public async Task The_loop_logs_repeatedly_while_uncancelled() + public async Task The_loop_logs_once_per_elapsed_interval_while_uncancelled() { + var time = new FakeTimeProvider(); + var interval = SupervisorLane.AcceptanceGradeHeartbeatInterval; var logger = new RecordingLogger(); using var cts = new CancellationTokenSource(); - var loop = Service(logger).RunGradingHeartbeatLoopAsync(RunId, NodeId, TimeSpan.FromMilliseconds(15), cts.Token); + var loop = Service(logger).RunGradingHeartbeatLoopAsync(RunId, NodeId, interval, cts.Token, time); - // Wait FOR the ticks, not for wall-clock — a loaded CI runner can starve a fixed 80ms window below three - // 15ms ticks (a thrice-observed flake), while three OBSERVED ticks prove the same thing deterministically: - // it's a REPEATING loop, not a one-shot. - var deadline = DateTimeOffset.UtcNow + TimeSpan.FromSeconds(10); - while (logger.Calls.Count < 3 && DateTimeOffset.UtcNow < deadline) - await Task.Delay(TimeSpan.FromMilliseconds(10)); + logger.Calls.ShouldBeEmpty("the first heartbeat is owed only once a full interval of grading has passed"); + + // Three OBSERVED ticks prove it is a REPEATING loop, not a one-shot — and on the fake clock the count after + // i intervals is exactly i, where the wall clock could only ever promise "at least". + for (var i = 1; i <= 3; i++) + { + await AdvanceUntilLoggedAsync(time, logger, interval, i); + + logger.Calls.Count.ShouldBe(i, $"exactly one heartbeat per elapsed interval — after {i} interval(s) there must be {i}"); + } cts.Cancel(); - await loop; + await loop.WaitAsync(TimeSpan.FromSeconds(10)); - logger.Calls.Count.ShouldBeGreaterThanOrEqualTo(3, "three heartbeats must land within 10s at a 15ms interval — check RunGradingHeartbeatLoopAsync's delay/loop wiring if this ever fires"); logger.Calls.ShouldAllBe(c => c.RunId == RunId && c.NodeId == NodeId && c.Level == LogLevel.Info); } [Fact] public async Task Cancelling_stops_the_loop_without_throwing() { + var time = new FakeTimeProvider(); + var interval = SupervisorLane.AcceptanceGradeHeartbeatInterval; var logger = new RecordingLogger(); using var cts = new CancellationTokenSource(); - var loop = Service(logger).RunGradingHeartbeatLoopAsync(RunId, NodeId, TimeSpan.FromMilliseconds(10), cts.Token); + var loop = Service(logger).RunGradingHeartbeatLoopAsync(RunId, NodeId, interval, cts.Token, time); + + // One tick first, so the cancel below lands MID-SLEEP on the next interval rather than before the loop ran. + await AdvanceUntilLoggedAsync(time, logger, interval, 1); - await Task.Delay(TimeSpan.FromMilliseconds(30)); cts.Cancel(); // Must complete cleanly — OperationCanceledException is caught INSIDE the loop, never surfaced to the caller - // (the P1.3 call site's finally-block await must never itself need a try/catch for this). - await Should.NotThrowAsync(() => loop); + // (the P1.3 call site's finally-block await must never itself need a try/catch for this). Recorded rather than + // asserted with Should.NotThrowAsync, which passes a CANCELED task without a word and so could never catch the + // very escape this test is named for. Bounded, so a loop that ignores the cancel mid-sleep fails, not hangs. + var escaped = await Record.ExceptionAsync(() => loop.WaitAsync(TimeSpan.FromSeconds(10))); + + escaped.ShouldBeNull("a cancel mid-sleep must end the loop at once and quietly — a TimeoutException means it outlived the grade it protects, a TaskCanceledException that the cancel escaped to the caller"); + + time.Advance(interval * 3); + (await logger.Logged.WaitAsync(TimeSpan.FromMilliseconds(200))).ShouldBeFalse("a cancelled loop logs no more heartbeats, however much time passes"); + logger.Calls.Count.ShouldBe(1); } [Fact] @@ -71,19 +94,44 @@ public async Task An_already_cancelled_token_produces_zero_heartbeats() using var cts = new CancellationTokenSource(); cts.Cancel(); - await Service(logger).RunGradingHeartbeatLoopAsync(RunId, NodeId, TimeSpan.FromMilliseconds(10), cts.Token); + await Service(logger).RunGradingHeartbeatLoopAsync(RunId, NodeId, SupervisorLane.AcceptanceGradeHeartbeatInterval, cts.Token, new FakeTimeProvider()).WaitAsync(TimeSpan.FromSeconds(10)); logger.Calls.ShouldBeEmpty("a grade that finishes before the FIRST tick never needs a heartbeat"); } - /// Minimal fake — every method a harmless no-op except , which records each call. The grading-heartbeat path touches ONLY LogAsync; every other member exists solely to satisfy the interface. + /// + /// Advances the fake clock until the loop logs heartbeat , rather than advancing one + /// whole interval and assuming the loop was already listening. + /// + /// The loop arms its next delay only AFTER the previous heartbeat's write returns, so a single Advance can + /// land before that registration and be missed — the clock then never moves again. Nudging in tenths of an + /// interval cannot fire a delay early, so the exact count asserted at the call site still means one heartbeat + /// per interval. Same shape as HeartbeatLoopTests. + /// + private static async Task AdvanceUntilLoggedAsync(FakeTimeProvider time, RecordingLogger logger, TimeSpan interval, int ordinal) + { + for (var nudge = 0; nudge < 200; nudge++) + { + if (await logger.Logged.WaitAsync(TimeSpan.FromMilliseconds(10))) return; + + time.Advance(interval / 10); + } + + throw new TimeoutException($"heartbeat {ordinal} never landed after advancing the fake clock well past its interval — the loop stopped repeating, or RunGradingHeartbeatLoopAsync is not sleeping on the TimeProvider it is handed"); + } + + /// Minimal fake — every method a harmless no-op except , which records each call and releases once it has. The grading-heartbeat path touches ONLY LogAsync; every other member exists solely to satisfy the interface. private sealed class RecordingLogger : IRunRecordLogger { public List<(Guid RunId, string? NodeId, LogLevel Level, string Message)> Calls { get; } = new(); + /// Released AFTER each call is recorded, so a waiter that acquires it reads a that already holds that heartbeat. + public SemaphoreSlim Logged { get; } = new(0); + public Task LogAsync(Guid runId, string? nodeId, LogLevel level, string message, CancellationToken cancellationToken) { Calls.Add((runId, nodeId, level, message)); + Logged.Release(); return Task.CompletedTask; } diff --git a/backend/tests/CodeSpace.UnitTests/Workflows/AgentCodeNodeTests.cs b/backend/tests/CodeSpace.UnitTests/Workflows/AgentCodeNodeTests.cs index 3f937db6e..639409571 100644 --- a/backend/tests/CodeSpace.UnitTests/Workflows/AgentCodeNodeTests.cs +++ b/backend/tests/CodeSpace.UnitTests/Workflows/AgentCodeNodeTests.cs @@ -941,7 +941,7 @@ public async Task A_respawn_after_a_host_loss_restores_the_checkpoint_and_says_t task.RestoredTranscript.ShouldBeNull("an abandoned attempt left no inline transcript, and inventing one would be a claim about bytes nobody has"); task.ResumedFromCheckpointAt.ShouldBe(new DateTimeOffset(2026, 9, 19, 10, 11, 12, TimeSpan.Zero), "the launch stamps this onto the run's permanent confinement record"); task.ResumedFromAgentRunId.ShouldBe(priorRunId, "which attempt took over from which is a column, not prose"); - task.Goal.ShouldContain("machine running your previous attempt was lost", Case.Sensitive, "a restored conversation describes a working tree this sandbox does not have, and the agent must be told"); + task.Goal.ShouldContain("the machine or the process running your previous attempt was lost", Case.Sensitive, "a restored conversation describes a working tree this sandbox does not have, and the agent must be told"); } [Fact] @@ -962,7 +962,7 @@ public async Task No_checkpoint_means_a_cold_retry_that_says_so() task.RestoredTranscriptArtifactId.ShouldBeNull("no checkpoint was taken, so there is no conversation to restore"); task.ResumedFromCheckpointAt.ShouldBeNull(); task.ResumedFromAgentRunId.ShouldBeNull(); - task.Goal.ShouldNotContain("machine running your previous attempt was lost", Case.Sensitive, "nothing may assert a restored conversation this attempt does not have"); + task.Goal.ShouldNotContain("the machine or the process running your previous attempt was lost", Case.Sensitive, "nothing may assert a restored conversation this attempt does not have"); } [Theory] @@ -1244,7 +1244,7 @@ public void The_honest_no_continuity_hint_is_pinned_verbatim() // agent the same thing about a tree that does not carry its prior work. The literal is pinned because the // supervisor's own behaviour test asserts this exact wording — a reword must be a visible decision. AgentRetryContinuity.HonestNoContinuityHint.ShouldBe( - "Note: your prior attempt's conversation is restored, but its git changes were NOT preserved in this workspace (no pushed branch was found to continue from) — you must redo any relevant file changes from scratch."); + "Note: your prior attempt's conversation is restored, but its git changes were NOT preserved in this workspace (your prior attempt pushed no branch of its own) — you must redo any relevant file changes from scratch."); } [Fact]