diff --git a/docs/reference/configuration.md b/docs/reference/configuration.md index 6c0d88de..0479f8f4 100644 --- a/docs/reference/configuration.md +++ b/docs/reference/configuration.md @@ -580,7 +580,9 @@ Hot-reloadable retry and recovery bounds used by pipeline execution. | `SuggestionDedupeSimilarityThreshold` | `0.6` | Minimum Jaccard similarity over a suggestion's normalized token signature (lower-cased, punctuation- and stop-word-stripped title tokens plus normalized file paths) for a repeat to merge into an existing row instead of creating a duplicate. Must be in (0, 1]. Hot-reloadable. | | `MergeLandingMaxAttempts` | `3` | Times a merge phase re-queues its landing after the base branch moves between composition and the conditional base-ref update. Retries do not consume the guard-rework budget. Past the cap the item parks at `MergeConflictResolutionFailed` with the recorded reason. Hot-reloadable. | | `MergeResultBuildVerificationEnabled` | `true` | Builds the exact merge-result tree with the required build in a sandbox before advancing the base branch, inside the shared per-base-branch landing queue. A failed build is a semantic conflict: the tree is not landed and the item takes conflict-rework turns briefed with the build errors. Hot-reloadable. | -| `MergeResultBuildVerificationTimeout` | `00:15:00` (15 min) | Upper bound for a single merge-result build verification. Exceeding it fails the verification (the item re-queues through rework and re-verifies) — an unverified tree is never landed. Must be positive. Hot-reloadable. | +| `MergeResultBuildVerificationTimeout` | unset (automatic) | Upper bound for a single merge-result build verification. Unset means the required-build budget plus `MergeResultBuildVerificationProvisioningAllowance`. An explicit value below that floor is clamped up (with a config-load warning), never applied as a silent cap. Exceeding the effective budget is infrastructure — retried up to `MergeResultBuildVerificationInfraMaxAttempts` without consuming the guard-rework budget — an unverified tree is never landed. Must be positive when set. Hot-reloadable. | +| `MergeResultBuildVerificationProvisioningAllowance` | `00:05:00` (5 min) | Sandbox-provisioning allowance added to the required-build budget to derive the effective merge-result verification budget (the inner required-build timeout covers clone/checkout/build after the verifier sandbox exists; the merge-result timeout is measured from sandbox acquisition). Must be non-negative. Hot-reloadable. | +| `MergeResultBuildVerificationInfraMaxAttempts` | `3` | Bounded retries for merge-result verifications that time out. Timeouts never consume the `MergeGuardReworkMaxAttempts` guard-rework budget; past this cap the item parks at `MergeConflictResolutionFailed` with a message naming both timeout settings. Must be ≥ 1. Hot-reloadable. | | `MergeGuardReworkMaxAttempts` | `2` | Conflict-rework turns after a resolver safety guard fires (edits outside the permitted conflict hunks, or a rework that discarded prior commits). Each turn runs on the refreshed base with the guard reason in the brief; past the cap the item parks at `MergeConflictResolutionFailed`. Hot-reloadable. | | `SuggestionDedupeDismissedMatchWindow` | `30.00:00:00` (30 days) | How far back a dismissed suggestion still attracts repeats: a matching suggestion dismissed within this window bumps its occurrence count instead of spawning a new row (the dismissal sticks). Open suggestions always match. Hot-reloadable. | | `SuggestionDedupeMaxRecordedSources` | `25` | Cap on the source work-item id list recorded on a merged suggestion. Once full, repeats still bump the occurrence count but stop appending ids. Must be ≥ 1. Hot-reloadable. | diff --git a/src/CodeyBox.Api/AgentConfigHotReload.cs b/src/CodeyBox.Api/AgentConfigHotReload.cs index 52f5eb74..2d984bc7 100644 --- a/src/CodeyBox.Api/AgentConfigHotReload.cs +++ b/src/CodeyBox.Api/AgentConfigHotReload.cs @@ -272,6 +272,7 @@ public async Task StartAsync(CancellationToken cancellationToken) await ApplyConfiguredAgentPausesAtStartupAsync(initial, cancellationToken); _subscription = _monitor.OnChange(OnConfigChanged); + LogMergeResultBuildBudgetWarningIfTooTight(initial); _log.LogInformation( "AgentConfigHotReload subscribed to CodeyBoxOptions: classes={ClassesLen} concurrency={ConcurrencyLen} burn={BurnLen} pricing={PricingLen} defaults={DefaultsLen} sanitizer={SanitizerLen} tolerance={ToleranceLen}", _lastRouter.Length, _lastConcurrency.Length, _lastBurn.Length, _lastPricing.Length, _lastDefaults.Length, _lastSanitizer.Length, _lastNetworkTolerance.Length); @@ -1508,7 +1509,13 @@ private void ApplyPipelineTuningIfChanged(CodeyBoxOptions opts) var next = SerializePipelineTuning(opts.PipelineTuning); if (string.Equals(_lastPipelineTuning, next, StringComparison.Ordinal)) + { + // The merge-result floor also depends on the required-build budget + // (restart-required): re-check the clamp warning even when the + // tuning block itself did not change. + LogMergeResultBuildBudgetWarningIfTooTight(opts); return; + } var prev = _lastPipelineTuning; try @@ -1519,6 +1526,7 @@ private void ApplyPipelineTuningIfChanged(CodeyBoxOptions opts) _lastPipelineTuning = next; AuditLog.ConfigReloaded("PipelineTuning", prev, next); _log.LogInformation("Hot-reloaded PipelineTuning: {OldValue} → {NewValue}", prev, next); + LogMergeResultBuildBudgetWarningIfTooTight(opts); } catch (Exception ex) { @@ -1529,6 +1537,22 @@ private void ApplyPipelineTuningIfChanged(CodeyBoxOptions opts) } } + /// + /// Config-load validation warning for the merge-result build budget: the + /// effective per-attempt budget is never below the required-build budget + /// plus the provisioning allowance, so an explicit + /// MergeResultBuildVerificationTimeout below that floor is clamped + /// up at verification time. This warning makes the clamp visible at load + /// (and on every reload) instead of a silent cap. + /// + private void LogMergeResultBuildBudgetWarningIfTooTight(CodeyBoxOptions opts) + { + ArgumentNullException.ThrowIfNull(opts); + var required = TimeSpan.FromSeconds(Math.Max(60, opts.RequiredBuildVerificationTimeoutSeconds)); + if (opts.PipelineTuning.TryGetMergeResultBuildBudgetWarning(required, out var warning)) + _log.LogWarning("{Warning}", warning); + } + private void ApplyBudgetDeferralRecheckIfChanged(CodeyBoxOptions opts) { if (_budgetDeferralRecheck is null) return; @@ -1627,7 +1651,9 @@ internal static string SerializePipelineTuning(PipelineTuningOptions opts) => opts.MergeLandingMaxAttempts, opts.MergeGuardReworkMaxAttempts, opts.MergeResultBuildVerificationEnabled, - MergeResultBuildVerificationTimeoutSeconds = opts.MergeResultBuildVerificationTimeout.TotalSeconds, + MergeResultBuildVerificationTimeoutSeconds = opts.MergeResultBuildVerificationTimeout?.TotalSeconds, + MergeResultBuildVerificationProvisioningAllowanceSeconds = opts.MergeResultBuildVerificationProvisioningAllowance.TotalSeconds, + opts.MergeResultBuildVerificationInfraMaxAttempts, opts.EnableSandboxReuse, opts.MaxSandboxReuses, MaxSandboxLifetimeSeconds = opts.MaxSandboxLifetime.TotalSeconds, diff --git a/src/CodeyBox.Orchestrator/MergeScopeFence.cs b/src/CodeyBox.Orchestrator/MergeScopeFence.cs index 03721cc6..d44a870b 100644 --- a/src/CodeyBox.Orchestrator/MergeScopeFence.cs +++ b/src/CodeyBox.Orchestrator/MergeScopeFence.cs @@ -61,6 +61,24 @@ public MergeResultBuildFailedException(string message, string buildOutput, Excep } } +/// +/// A merge-result build verification that timed out without proving the +/// merged tree: infrastructure, never a semantic verdict on the diff. The +/// merge landing retries these up to +/// +/// without consuming the +/// guard-rework budget (which exists for real semantic failures); only after +/// the infra budget is spent does the item park, with a message naming both +/// timeout settings so a too-tight budget is actionable. +/// +public sealed class MergeResultBuildVerificationTimeoutException : MergeConflictResolutionFailedException +{ + public MergeResultBuildVerificationTimeoutException(string message, Exception? innerException = null) + : base(message, innerException, failureKind: WorkItemFailureKinds.Infrastructure, phase: "merge") + { + } +} + /// /// Retryable signal that the base branch moved between merge composition /// and landing (the conditional update-ref refused to advance). @@ -113,10 +131,15 @@ internal static bool IsResolverGuardFailure(MergeConflictResolutionFailedExcepti { if (current is MergeBaseMovedException) return false; + if (current is MergeResultBuildVerificationTimeoutException) + return false; if (current is ScopeFenceViolation) return true; } + if (ex is MergeResultBuildVerificationTimeoutException) + return false; + return ex.Message.Contains("outside the permitted conflict hunks", StringComparison.Ordinal) || ex.Message.Contains("discarded prior commits", StringComparison.Ordinal) || ex.Message.Contains("was not part of the resolved diff", StringComparison.Ordinal) diff --git a/src/CodeyBox.Orchestrator/PipelineRunner.Merge.cs b/src/CodeyBox.Orchestrator/PipelineRunner.Merge.cs index f4b2755a..588adf4b 100644 --- a/src/CodeyBox.Orchestrator/PipelineRunner.Merge.cs +++ b/src/CodeyBox.Orchestrator/PipelineRunner.Merge.cs @@ -714,6 +714,20 @@ await _store.UpdateAsync(current with /// base. Verifier infrastructure failures propagate untouched (parked /// as infrastructure, never landed, never misattributed to the diff). /// + /// + /// + /// A verification that times out is infrastructure, not a verdict on the + /// diff: it is retried up to + /// + /// without consuming the guard-rework budget, and only parks (as + /// ) once the + /// infra budget is spent. The per-attempt budget is the single source of + /// truth in + /// , + /// never below the required-build budget plus the provisioning + /// allowance. Every attempt reports its duration in the structured log + /// so a too-tight budget is visible. + /// /// private async Task VerifyMergeBuildAndLandAsync( WorkItem item, @@ -753,28 +767,95 @@ private async Task VerifyMergeBuildAndLandAsync( await _gitHost.SetBranchToCommitAsync(repoId, verifyBranch, mergeSha, ct); try { - var timeout = _pipelineTuning.Current.MergeResultBuildVerificationTimeout; - using var timeoutCts = new CancellationTokenSource(timeout); - using var linkedCts = CancellationTokenSource.CreateLinkedTokenSource(ct, timeoutCts.Token); - RequiredBuildVerificationResult result; - try + // Snapshot the budgets once: an in-flight verification keeps a + // stable per-attempt budget while the next landing observes a + // configuration edit. + var tuning = _pipelineTuning.Current; + var requiredBuildTimeout = _opts.RequiredBuildVerificationTimeout; + var configuredMergeTimeout = tuning.MergeResultBuildVerificationTimeout; + var effectiveTimeout = tuning.GetEffectiveMergeResultBuildVerificationTimeout(requiredBuildTimeout); + var maxAttempts = Math.Max(1, tuning.MergeResultBuildVerificationInfraMaxAttempts); + if (tuning.TryGetMergeResultBuildBudgetWarning(requiredBuildTimeout, out var budgetWarning)) { - result = await _requiredBuildGate.VerifyMergeResultAsync( - item, project, repoId, baseBranch, verifyBranch, linkedCts.Token); - } - catch (OperationCanceledException ex) when (!ct.IsCancellationRequested && timeoutCts.IsCancellationRequested) - { - throw new MergeConflictResolutionFailedException( - $"merge-result build verification timed out after {timeout} without proving the merged tree; refusing to land an unverified tree", - ex); + _log.LogWarning( + "Merge-result build verification budget clamped for work item {WorkItemId}: {Warning} " + + "(configured MergeResultBuildVerificationTimeout={Configured}, " + + "RequiredBuildVerificationTimeout={Required}, effective={Effective})", + item.Id, budgetWarning, configuredMergeTimeout, requiredBuildTimeout, effectiveTimeout); } - if (result.Status == RequiredBuildVerificationStatus.Failed) + for (var attempt = 1; ; attempt++) { - var summary = RequiredBuildGate.BuildFailureSummary(result); - throw new MergeResultBuildFailedException( - $"merge result failed required build (semantic conflict against '{baseBranch}'): {summary}", - result.Output); + var attemptStart = _opts.TimeProvider.GetUtcNow(); + // TimeProvider-backed so tests drive the budget with a + // FakeTimeProvider instead of racing wall-clock scheduling. + using var timeoutCts = new CancellationTokenSource(effectiveTimeout, _opts.TimeProvider); + using var linkedCts = CancellationTokenSource.CreateLinkedTokenSource(ct, timeoutCts.Token); + RequiredBuildVerificationResult result; + try + { + result = await _requiredBuildGate.VerifyMergeResultAsync( + item, project, repoId, baseBranch, verifyBranch, linkedCts.Token); + } + catch (OperationCanceledException ex) when (!ct.IsCancellationRequested && timeoutCts.IsCancellationRequested) + { + var timedOutElapsed = _opts.TimeProvider.GetUtcNow() - attemptStart; + var retryAction = attempt < maxAttempts + ? "retrying as infrastructure without consuming the guard-rework budget" + : "infra retry budget spent; parking without landing the unverified tree"; + _log.LogWarning( + ex, + "Merge-result build verification attempt {Attempt}/{MaxAttempts} for work item {WorkItemId} " + + "timed out after {Elapsed} (budget {Budget}); {Action}", + attempt, maxAttempts, item.Id, timedOutElapsed, effectiveTimeout, retryAction); + if (attempt < maxAttempts) + continue; + + throw new MergeResultBuildVerificationTimeoutException( + FormatMergeVerificationTimeoutMessage( + maxAttempts, effectiveTimeout, timedOutElapsed, + requiredBuildTimeout, configuredMergeTimeout), + ex); + } + + // The inner verifier's own required-build budget firing is + // the same infrastructure outcome as the outer budget + // firing: the build never proved the tree, so this is not + // a semantic conflict and must not route to rework. + if (SandboxRequiredBuildVerifier.IsBuildTimeoutResult(result)) + { + var innerElapsed = _opts.TimeProvider.GetUtcNow() - attemptStart; + var innerRetryAction = attempt < maxAttempts + ? "retrying as infrastructure without consuming the guard-rework budget" + : "infra retry budget spent; parking without landing the unverified tree"; + _log.LogWarning( + "Merge-result build verification attempt {Attempt}/{MaxAttempts} for work item {WorkItemId} " + + "hit the inner required-build timeout after {Elapsed} (budget {Budget}); {Action}", + attempt, maxAttempts, item.Id, innerElapsed, effectiveTimeout, innerRetryAction); + if (attempt < maxAttempts) + continue; + + throw new MergeResultBuildVerificationTimeoutException( + FormatMergeVerificationTimeoutMessage( + maxAttempts, effectiveTimeout, innerElapsed, + requiredBuildTimeout, configuredMergeTimeout)); + } + + var elapsed = _opts.TimeProvider.GetUtcNow() - attemptStart; + _log.LogInformation( + "Merge-result build verification attempt {Attempt}/{MaxAttempts} for work item {WorkItemId} " + + "finished in {Elapsed} with status {Status} (budget {Budget})", + attempt, maxAttempts, item.Id, elapsed, result.Status, effectiveTimeout); + + if (result.Status == RequiredBuildVerificationStatus.Failed) + { + var summary = RequiredBuildGate.BuildFailureSummary(result); + throw new MergeResultBuildFailedException( + $"merge result failed required build (semantic conflict against '{baseBranch}'): {summary}", + result.Output); + } + + break; } } finally @@ -790,6 +871,20 @@ private async Task VerifyMergeBuildAndLandAsync( } } + private static string FormatMergeVerificationTimeoutMessage( + int maxAttempts, + TimeSpan effectiveTimeout, + TimeSpan lastAttemptElapsed, + TimeSpan requiredBuildTimeout, + TimeSpan? configuredMergeTimeout) + => "merge-result build verification timed out after " + + $"{maxAttempts} attempt(s) of {effectiveTimeout} (last attempt ran {lastAttemptElapsed}) " + + "without proving the merged tree; refusing to land an unverified tree " + + $"(RequiredBuildVerificationTimeout={requiredBuildTimeout}, " + + $"PipelineTuning:MergeResultBuildVerificationTimeout={configuredMergeTimeout?.ToString() ?? "unset (automatic)"}). " + + "Raise MergeResultBuildVerificationTimeout (it must cover RequiredBuildVerificationTimeout " + + "plus sandbox provisioning) and re-dispatch the item."; + /// /// Best-effort removal of the short-lived merge-verification branch. /// Deletes only when the ref still points at : diff --git a/src/CodeyBox.Orchestrator/PipelineRunner.cs b/src/CodeyBox.Orchestrator/PipelineRunner.cs index 4144634e..0dcacad4 100644 --- a/src/CodeyBox.Orchestrator/PipelineRunner.cs +++ b/src/CodeyBox.Orchestrator/PipelineRunner.cs @@ -922,6 +922,15 @@ await RunWithStuckProbeAsync(trialItem, project, runner.Kind, "merge", mergePhas if (firstFailure.InnerException is MergeBaseMovedException) throw; + // A merge-result verification timeout already exhausted its + // own bounded infra retry budget inside the landing queue: + // the tree was never proven, so no agent rework turn can + // repair it. Park directly without burning the + // guard-rework budget, which exists for real semantic + // failures. + if (firstFailure is MergeResultBuildVerificationTimeoutException) + throw; + // Third-line fallback: c9fd5b75 (preventive auto-rebase) and the // merge-phase agent (77ce33c667 on 405 race) have both run their // course. Re-engage the ORIGINAL work agent — who knows why this @@ -984,6 +993,8 @@ await RunWithStuckProbeAsync(trialItem, project, runner.Kind, "merge", mergePhas { if (next.InnerException is MergeBaseMovedException) throw; + if (next is MergeResultBuildVerificationTimeoutException) + throw; lastFailure = next; } } diff --git a/src/CodeyBox.Orchestrator/PipelineTuningHotReloadPolicy.cs b/src/CodeyBox.Orchestrator/PipelineTuningHotReloadPolicy.cs index 9fca61e3..bd9048d5 100644 --- a/src/CodeyBox.Orchestrator/PipelineTuningHotReloadPolicy.cs +++ b/src/CodeyBox.Orchestrator/PipelineTuningHotReloadPolicy.cs @@ -44,6 +44,8 @@ public static class PipelineTuningHotReloadPolicy nameof(PipelineTuningOptions.MergeLandingMaxAttempts), nameof(PipelineTuningOptions.MergeResultBuildVerificationEnabled), nameof(PipelineTuningOptions.MergeResultBuildVerificationTimeout), + nameof(PipelineTuningOptions.MergeResultBuildVerificationProvisioningAllowance), + nameof(PipelineTuningOptions.MergeResultBuildVerificationInfraMaxAttempts), nameof(PipelineTuningOptions.MergeGuardReworkMaxAttempts), nameof(PipelineTuningOptions.EnableSandboxReuse), nameof(PipelineTuningOptions.MaxSandboxReuses), diff --git a/src/CodeyBox.Orchestrator/PipelineTuningOptions.cs b/src/CodeyBox.Orchestrator/PipelineTuningOptions.cs index 70500c7b..00cb39f5 100644 --- a/src/CodeyBox.Orchestrator/PipelineTuningOptions.cs +++ b/src/CodeyBox.Orchestrator/PipelineTuningOptions.cs @@ -137,13 +137,91 @@ public sealed class PipelineTuningOptions /// /// Upper bound for a single merge-result build verification, measured - /// from sandbox acquisition through build completion. Exceeding it - /// fails the verification (the item re-queues through rework and - /// re-verifies) — an unverified tree is never landed. Must be - /// positive. Default 15 minutes. Hot-reloaded with the rest of + /// from sandbox acquisition through build completion. The verification + /// runs the SAME required-build command as the work-phase gate, so the + /// effective budget is never below + /// RequiredBuildVerificationTimeout + MergeResultBuildVerificationProvisioningAllowance + /// (see ): + /// an explicit value below that floor is clamped up and reported via + /// , never applied as a + /// silent cap. Unset (null, the default) means fully automatic: + /// the effective budget is exactly the required-build budget plus the + /// provisioning allowance, with no warning. Exceeding the effective + /// budget is infrastructure (retried up to + /// ), never a + /// semantic conflict — an unverified tree is never landed. An explicit + /// value must be positive. Hot-reloaded with the rest of /// PipelineTuning. /// - public TimeSpan MergeResultBuildVerificationTimeout { get; set; } = TimeSpan.FromMinutes(15); + public TimeSpan? MergeResultBuildVerificationTimeout { get; set; } + + /// + /// Sandbox-provisioning allowance added to the required-build budget to + /// derive the effective merge-result verification budget: the inner + /// required-build timeout covers clone/checkout/build AFTER the verifier + /// sandbox exists, while the merge-result timeout is measured from + /// sandbox acquisition, so provisioning must not eat the build's own + /// budget. Must be non-negative. Default 5 minutes. Hot-reloaded with + /// the rest of PipelineTuning. + /// + public TimeSpan MergeResultBuildVerificationProvisioningAllowance { get; set; } = TimeSpan.FromMinutes(5); + + /// + /// Maximum merge-result build verification attempts spent on timeout + /// (infrastructure) outcomes before parking. A verification that times + /// out is retried without consuming the + /// guard-rework budget, which + /// exists for real semantic failures; only after this infra budget is + /// spent does the item park at MergeConflictResolutionFailed with + /// a message naming both timeout settings. Must be ≥ 1. Default 3. + /// Hot-reloaded with the rest of PipelineTuning. + /// + public int MergeResultBuildVerificationInfraMaxAttempts { get; set; } = 3; + + /// + /// Effective per-attempt merge-result build verification budget: the + /// single source of truth shared by the merge landing queue. Never below + /// the required-build budget plus the provisioning allowance, so an + /// operator who raised the required-build budget for a slow host cannot + /// be silently capped by a stale merge-result setting. Unset means + /// exactly the floor (required + allowance); an explicit value below the + /// floor is clamped up to it. + /// + public TimeSpan GetEffectiveMergeResultBuildVerificationTimeout(TimeSpan requiredBuildVerificationTimeout) + { + var floor = requiredBuildVerificationTimeout + MergeResultBuildVerificationProvisioningAllowance; + return MergeResultBuildVerificationTimeout is { } configured && configured > floor + ? configured + : floor; + } + + /// + /// True when an explicit merge-result timeout sits below the + /// required-build-derived floor and will be clamped up by + /// . + /// Unset never warns: automatic means the floor by definition. Callers + /// log at config load / verification time so + /// the clamp is never silent. + /// + public bool TryGetMergeResultBuildBudgetWarning( + TimeSpan requiredBuildVerificationTimeout, + out string warning) + { + var floor = requiredBuildVerificationTimeout + MergeResultBuildVerificationProvisioningAllowance; + if (MergeResultBuildVerificationTimeout is not { } configured || configured >= floor) + { + warning = string.Empty; + return false; + } + + warning = + $"CodeyBox:PipelineTuning:MergeResultBuildVerificationTimeout ({configured}) " + + $"is below RequiredBuildVerificationTimeout ({requiredBuildVerificationTimeout}) + " + + $"provisioning allowance ({MergeResultBuildVerificationProvisioningAllowance}); " + + $"clamping the effective merge-result budget up to {floor}. " + + "Raise MergeResultBuildVerificationTimeout (or unset it for automatic) or lower the required-build budget to silence this warning."; + return true; + } /// /// Maximum conflict-rework turns the merge phase runs after a resolver @@ -527,11 +605,23 @@ public void Validate() nameof(MergeGuardReworkMaxAttempts), "MergeGuardReworkMaxAttempts must be >= 1"); } - if (MergeResultBuildVerificationTimeout <= TimeSpan.Zero) + if (MergeResultBuildVerificationTimeout is { } mergeTimeout && mergeTimeout <= TimeSpan.Zero) { throw new ArgumentOutOfRangeException( nameof(MergeResultBuildVerificationTimeout), - "MergeResultBuildVerificationTimeout must be positive"); + "MergeResultBuildVerificationTimeout must be positive when set"); + } + if (MergeResultBuildVerificationProvisioningAllowance < TimeSpan.Zero) + { + throw new ArgumentOutOfRangeException( + nameof(MergeResultBuildVerificationProvisioningAllowance), + "MergeResultBuildVerificationProvisioningAllowance must be non-negative"); + } + if (MergeResultBuildVerificationInfraMaxAttempts < 1) + { + throw new ArgumentOutOfRangeException( + nameof(MergeResultBuildVerificationInfraMaxAttempts), + "MergeResultBuildVerificationInfraMaxAttempts must be >= 1"); } if (EarlyEndedTurnMaxNudges < 0) { diff --git a/src/CodeyBox.Orchestrator/SandboxRequiredBuildVerifier.cs b/src/CodeyBox.Orchestrator/SandboxRequiredBuildVerifier.cs index fc9854e1..50963733 100644 --- a/src/CodeyBox.Orchestrator/SandboxRequiredBuildVerifier.cs +++ b/src/CodeyBox.Orchestrator/SandboxRequiredBuildVerifier.cs @@ -33,7 +33,24 @@ public sealed class SandboxRequiredBuildVerifier : IRequiredBuildVerifier private const int MaxDotnetMarkerPathsPerBranch = 8192; // Internal verifier sentinel for branch-controlled clone / checkout / build // execution exceeding the required-build budget. - private const int BuildTimeoutExitCode = 124; + internal const int BuildTimeoutExitCode = 124; + + /// + /// True when is the verifier's own required-build + /// budget timeout (exit 124 with the timeout output): infrastructure, not a + /// verdict on the diff. The merge landing treats these exactly like its own + /// outer verification timeout — bounded infra retries, never a semantic + /// conflict and never guard-budget consumption. + /// + internal static bool IsBuildTimeoutResult(RequiredBuildVerificationResult result) + { + ArgumentNullException.ThrowIfNull(result); + return result.Status == RequiredBuildVerificationStatus.Failed + && result.ExitCode == BuildTimeoutExitCode + && result.Output.Contains( + "build exceeded the required-build verification timeout", + StringComparison.Ordinal); + } // POSIX-sh prologue that guarantees the dotnet/NuGet home points at a // directory we can actually create NuGet's user-config folder under, BEFORE diff --git a/tests/CodeyBox.Tests/ConfigReloadClassificationTests.cs b/tests/CodeyBox.Tests/ConfigReloadClassificationTests.cs index 6a322339..2c3a9e96 100644 --- a/tests/CodeyBox.Tests/ConfigReloadClassificationTests.cs +++ b/tests/CodeyBox.Tests/ConfigReloadClassificationTests.cs @@ -599,7 +599,14 @@ private static void MutatePipelineTuningField(PipelineTuningOptions opts, string opts.MergeResultBuildVerificationEnabled = !opts.MergeResultBuildVerificationEnabled; break; case nameof(PipelineTuningOptions.MergeResultBuildVerificationTimeout): - opts.MergeResultBuildVerificationTimeout += TimeSpan.FromHours(1); + opts.MergeResultBuildVerificationTimeout = + (opts.MergeResultBuildVerificationTimeout ?? TimeSpan.FromMinutes(15)) + TimeSpan.FromHours(1); + break; + case nameof(PipelineTuningOptions.MergeResultBuildVerificationProvisioningAllowance): + opts.MergeResultBuildVerificationProvisioningAllowance += TimeSpan.FromMinutes(1); + break; + case nameof(PipelineTuningOptions.MergeResultBuildVerificationInfraMaxAttempts): + opts.MergeResultBuildVerificationInfraMaxAttempts += 10; break; default: throw new ArgumentOutOfRangeException(nameof(field), field, "No mutator for this PipelineTuning field."); diff --git a/tests/CodeyBox.Tests/MergeResultBuildVerificationTests.cs b/tests/CodeyBox.Tests/MergeResultBuildVerificationTests.cs index 915de8c7..f018f39f 100644 --- a/tests/CodeyBox.Tests/MergeResultBuildVerificationTests.cs +++ b/tests/CodeyBox.Tests/MergeResultBuildVerificationTests.cs @@ -3,6 +3,8 @@ using CodeyBox.Core; using CodeyBox.Orchestrator; using CodeyBox.Projects; +using Microsoft.Extensions.Logging; +using MergeClock = Microsoft.Extensions.Time.Testing.FakeTimeProvider; namespace CodeyBox.Tests; @@ -232,6 +234,115 @@ public async Task VerificationDisabled_LandsWithoutVerifying() Assert.Equal("feature\n", feature); } + /// + /// A merge-result verification that times out is infrastructure, not a + /// semantic verdict: it is retried a bounded number of times without + /// consuming the guard-rework budget (which exists for real semantic + /// failures), and only parks once the infra budget is spent — with a + /// message naming both timeout settings and a per-attempt duration in + /// the structured log so a too-tight budget is visible. The timeout + /// budget runs on the pipeline clock, so the fake clock drives it + /// deterministically. + /// + [Fact] + public async Task VerificationTimeout_RetriesBoundedInfraAttempts_ThenParksWithoutConsumingGuardBudget() + { + var seed = await TestSupport.CreateSeedRepoAsync(_workspace, "seed-merge-verify-timeout"); + var verifier = new DelegateBuildVerifier(); + var clock = new MergeClock(DateTimeOffset.UtcNow); + const int infraMaxAttempts = 2; + var tuning = new PipelineTuningSnapshot(new PipelineTuningOptions + { + MergeResultBuildVerificationTimeout = TimeSpan.FromMilliseconds(200), + MergeResultBuildVerificationProvisioningAllowance = TimeSpan.Zero, + MergeResultBuildVerificationInfraMaxAttempts = infraMaxAttempts, + }); + var pipelineOptions = new PipelineOptions + { + SandboxImageReference = "ignored", + AgentAllowedHosts = [], + // A generous inner budget so the floor (required + allowance) + // cannot clamp the 200 ms merge budget under test. + RequiredBuildVerificationTimeout = TimeSpan.FromMilliseconds(100), + }; + var logs = new ListLogger(); + using var tp = TestSupport.BuildPipeline( + _workspace, seed, + requiredBuildVerifier: verifier, + pipelineTuning: tuning, + pipelineOptions: pipelineOptions, + pipelineTimeProvider: clock, + logger: logs); + tp.Agent.WorkPlan.Enqueue(new FileWrite("feature.txt", "feature\n")); + + var item = NewItem("codeybox/merge-verify-timeout-" + WorkItemId.New().ToString()[..8]); + await tp.Store.CreateAsync(item); + verifier.OnVerifyAsync = async (request, ct) => + { + if (!IsVerifyBranch(request.WorkBranch)) + return RequiredBuildVerificationResult.Passed(0, "work-branch head builds"); + // Hang until the merge-result budget cancels us: the attempt must + // end in a timeout, never in a build verdict. + await Task.Delay(Timeout.InfiniteTimeSpan, ct); + return RequiredBuildVerificationResult.Passed(0, "unreachable"); + }; + + await RunWithAdvancingClockAsync(clock, tp.Pipeline.RunAsync(item, CancellationToken.None)); + + var final = await tp.Store.GetAsync(item.Id); + Assert.Equal(WorkItemState.MergeConflictResolutionFailed, final!.State); + Assert.Equal(WorkItemFailureKinds.Infrastructure, final.FailureKind); + // Bounded infra retries: exactly one verification per attempt. + var mergeVerifies = verifier.VerificationRequests.Where(r => IsVerifyBranch(r.WorkBranch)).ToList(); + Assert.Equal(infraMaxAttempts, mergeVerifies.Count); + // The guard-rework budget is untouched: a timeout is infrastructure, + // so no conflict-rework turn ever ran. + Assert.Equal(0, final.ConflictReworkAttempts); + Assert.Empty(tp.Agent.ConflictReworkPrompts); + // The park message names both settings so the operator can act. + Assert.Contains("RequiredBuildVerificationTimeout", final.LastError, StringComparison.Ordinal); + Assert.Contains("MergeResultBuildVerificationTimeout", final.LastError, StringComparison.Ordinal); + // Every attempt reported its duration in the structured log. + var attemptLogs = logs.Lines + .Where(line => line.Message.Contains("Merge-result build verification attempt", StringComparison.Ordinal)) + .ToList(); + Assert.Equal(infraMaxAttempts, attemptLogs.Count); + Assert.All(attemptLogs, line => Assert.Contains("timed out after", line.Message, StringComparison.Ordinal)); + } + + private static async Task RunWithAdvancingClockAsync(MergeClock clock, Task pipelineTask) + { + ArgumentNullException.ThrowIfNull(clock); + ArgumentNullException.ThrowIfNull(pipelineTask); + // Advance the fake clock in lockstep with real time (10 ms fake per + // ~10 ms real delay) — never faster, so no other pipeline budget + // fires spuriously early while the merge-result budget under test + // elapses deterministically. + while (!pipelineTask.IsCompleted) + { + clock.Advance(TimeSpan.FromMilliseconds(10)); + await Task.Delay(10); + } + + await pipelineTask; + } + + private sealed class ListLogger : ILogger + { + public List<(LogLevel Level, string Message)> Lines { get; } = new(); + IDisposable? ILogger.BeginScope(TState state) => null; + public bool IsEnabled(LogLevel logLevel) => true; + public void Log( + LogLevel logLevel, + EventId eventId, + TState state, + Exception? exception, + Func formatter) + { + lock (Lines) Lines.Add((logLevel, formatter(state, exception))); + } + } + private sealed class DelegateBuildVerifier : IRequiredBuildVerifier { public RequiredBuildProbeResult ProbeResult { get; set; } = RequiredBuildProbeResult.Applies; diff --git a/tests/CodeyBox.Tests/PipelineTuningOptionsValidationTests.cs b/tests/CodeyBox.Tests/PipelineTuningOptionsValidationTests.cs index ef8283f7..7c757542 100644 --- a/tests/CodeyBox.Tests/PipelineTuningOptionsValidationTests.cs +++ b/tests/CodeyBox.Tests/PipelineTuningOptionsValidationTests.cs @@ -169,6 +169,100 @@ public void Validate_EmptyAdvisoryList_Allowed() opts.Validate(); } + [Fact] + public void EffectiveMergeBudget_DefaultsToRequiredPlusAllowance() + { + // The incident: an operator raised the required-build budget to 45 + // minutes but the 15-minute merge-result default silently capped every + // merge verification. The effective budget must never sit below the + // required-build budget plus the provisioning allowance. + var opts = new PipelineTuningOptions(); + opts.Validate(); + + var effective = opts.GetEffectiveMergeResultBuildVerificationTimeout(TimeSpan.FromMinutes(45)); + + Assert.True( + effective >= TimeSpan.FromMinutes(45), + $"effective merge budget {effective} must cover the 45-minute required-build budget"); + Assert.Equal( + TimeSpan.FromMinutes(45) + opts.MergeResultBuildVerificationProvisioningAllowance, + effective); + } + + [Fact] + public void EffectiveMergeBudget_Unset_NeverWarns() + { + var opts = new PipelineTuningOptions { MergeResultBuildVerificationTimeout = null }; + opts.Validate(); + + Assert.False( + opts.TryGetMergeResultBuildBudgetWarning(TimeSpan.FromMinutes(45), out _), + "unset means automatic (exactly the floor), so there is nothing to warn about"); + } + + [Fact] + public void EffectiveMergeBudget_ExplicitShortValue_ClampsUpWithWarning() + { + var opts = new PipelineTuningOptions + { + MergeResultBuildVerificationTimeout = TimeSpan.FromMinutes(5), + }; + opts.Validate(); + + var required = TimeSpan.FromMinutes(45); + var effective = opts.GetEffectiveMergeResultBuildVerificationTimeout(required); + + Assert.Equal(required + opts.MergeResultBuildVerificationProvisioningAllowance, effective); + Assert.True( + opts.TryGetMergeResultBuildBudgetWarning(required, out var warning), + "a configured merge budget below the required-build floor must produce a warning, never a silent cap"); + Assert.Contains("MergeResultBuildVerificationTimeout", warning, StringComparison.Ordinal); + Assert.Contains("RequiredBuildVerificationTimeout", warning, StringComparison.Ordinal); + } + + [Fact] + public void EffectiveMergeBudget_GenerousExplicitValue_NoWarning() + { + var opts = new PipelineTuningOptions + { + MergeResultBuildVerificationTimeout = TimeSpan.FromHours(2), + }; + opts.Validate(); + + var required = TimeSpan.FromMinutes(45); + + Assert.Equal(TimeSpan.FromHours(2), opts.GetEffectiveMergeResultBuildVerificationTimeout(required)); + Assert.False(opts.TryGetMergeResultBuildBudgetWarning(required, out _)); + } + + [Fact] + public void Validate_NegativeMergeProvisioningAllowance_Throws() + { + var opts = new PipelineTuningOptions + { + MergeResultBuildVerificationProvisioningAllowance = TimeSpan.FromSeconds(-1), + }; + + var ex = Assert.Throws(opts.Validate); + Assert.Equal( + nameof(PipelineTuningOptions.MergeResultBuildVerificationProvisioningAllowance), + ex.ParamName); + } + + [Fact] + public void Validate_ZeroMergeInfraMaxAttempts_Throws() + { + var opts = new PipelineTuningOptions + { + MergeResultBuildVerificationInfraMaxAttempts = 0, + }; + + var ex = Assert.Throws(opts.Validate); + Assert.Equal( + nameof(PipelineTuningOptions.MergeResultBuildVerificationInfraMaxAttempts), + ex.ParamName); + } + [Fact] public void Validate_NegativeSandboxPermitWaitWarningThreshold_Throws() {