From d7c3e1ef160639d1f59d6bfd161f451d4c45a3be Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Tue, 8 Sep 2026 18:49:15 -0700 Subject: [PATCH 01/22] fix(validator): add Job-deadline headroom constants Signed-off-by: Alex Yuskauskas --- pkg/defaults/timeouts.go | 16 +++++++++++++--- pkg/defaults/timeouts_test.go | 16 +++++++++++++++- 2 files changed, 28 insertions(+), 4 deletions(-) diff --git a/pkg/defaults/timeouts.go b/pkg/defaults/timeouts.go index 06da268656..fdb4e51f07 100644 --- a/pkg/defaults/timeouts.go +++ b/pkg/defaults/timeouts.go @@ -1140,9 +1140,19 @@ const ( // Validator constants. const ( - // ValidatorWaitBuffer is added to the catalog timeout when waiting for Job - // completion. Accounts for pod scheduling, image pull, and graceful termination. - ValidatorWaitBuffer = 30 * time.Second + // ValidatorWaitBuffer is added to the catalog timeout when the orchestrator + // waits for Job completion. It must exceed the delay between Job creation + // and the validator container's first instruction, or the orchestrator + // abandons the wait before the check's own clean exit and reports an + // orchestrator timeout in place of the check's verdict. + ValidatorWaitBuffer = K8sPodReadyTimeout + ValidatorTerminationGracePeriod + + // ValidatorJobDeadlineHeadroom is the gap between a check's own budget + // (AICR_CHECK_TIMEOUT) and the Job's activeDeadlineSeconds. Sized so the + // orchestrator is always the tighter clock: on exhaustion the check + // self-terminates and its pod stays Failed-but-present for log extraction, + // instead of the Job controller deleting it as an active pod (issue #2473). + ValidatorJobDeadlineHeadroom = ValidatorWaitBuffer + JobEnvelopeMargin // ValidatorDefaultTimeout is the default per-validator timeout if not // specified in the catalog. Used as fallback only. diff --git a/pkg/defaults/timeouts_test.go b/pkg/defaults/timeouts_test.go index 789e8bef77..36d0859587 100644 --- a/pkg/defaults/timeouts_test.go +++ b/pkg/defaults/timeouts_test.go @@ -70,7 +70,8 @@ func TestTimeoutConstants(t *testing.T) { {"TrainerControllerReadyTimeout", TrainerControllerReadyTimeout, 1 * time.Minute, 5 * time.Minute}, // Validator timeouts - {"ValidatorWaitBuffer", ValidatorWaitBuffer, 10 * time.Second, 60 * time.Second}, + {"ValidatorWaitBuffer", ValidatorWaitBuffer, 1 * time.Minute, 5 * time.Minute}, + {"ValidatorJobDeadlineHeadroom", ValidatorJobDeadlineHeadroom, 1 * time.Minute, 10 * time.Minute}, {"ValidatorDefaultTimeout", ValidatorDefaultTimeout, 1 * time.Minute, 15 * time.Minute}, {"ValidatorTerminationGracePeriod", ValidatorTerminationGracePeriod, 10 * time.Second, 60 * time.Second}, @@ -266,6 +267,19 @@ func TestValidatorTimeoutRelationships(t *testing.T) { t.Errorf("ValidatorTerminationGracePeriod (%v) should not exceed ValidatorWaitBuffer (%v)", ValidatorTerminationGracePeriod, ValidatorWaitBuffer) } + // The orchestrator must outlive the pod's own clean exit, so the wait + // buffer has to cover pod-start latency (scheduling + image pull). + if ValidatorWaitBuffer < K8sPodReadyTimeout { + t.Errorf("ValidatorWaitBuffer (%v) must be at least K8sPodReadyTimeout (%v)", + ValidatorWaitBuffer, K8sPodReadyTimeout) + } + // Kubernetes must be the LOOSEST clock. If the Job deadline is not + // strictly beyond the orchestrator's wait, the Job controller can kill and + // delete the pod before the orchestrator reads its logs — issue #2473. + if ValidatorJobDeadlineHeadroom <= ValidatorWaitBuffer { + t.Errorf("ValidatorJobDeadlineHeadroom (%v) must exceed ValidatorWaitBuffer (%v)", + ValidatorJobDeadlineHeadroom, ValidatorWaitBuffer) + } // Default timeout must be positive and reasonable. if ValidatorDefaultTimeout < 1*time.Minute { t.Errorf("ValidatorDefaultTimeout (%v) should be at least 1m", ValidatorDefaultTimeout) From 11a79263efc3c1b25b27b20f7d440cd4ba839936 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Tue, 8 Sep 2026 18:59:12 -0700 Subject: [PATCH 02/22] fix(validator): give the Job deadline headroom over the check budget Signed-off-by: Alex Yuskauskas --- pkg/validator/catalog/catalog_test.go | 67 +++++++++++++++++++++++++-- pkg/validator/v1/job_plan.go | 25 ++++++++-- pkg/validator/v1/job_plan_test.go | 8 ++-- 3 files changed, 87 insertions(+), 13 deletions(-) diff --git a/pkg/validator/catalog/catalog_test.go b/pkg/validator/catalog/catalog_test.go index 478f05223f..6de1f57de5 100644 --- a/pkg/validator/catalog/catalog_test.go +++ b/pkg/validator/catalog/catalog_test.go @@ -41,10 +41,17 @@ func TestCatalogTimeoutsFitFacadeBudget(t *testing.T) { t.Fatalf("Load() failed: %v", err) } for _, v := range catalog.Validators { - if v.Timeout >= defaults.ValidationOperationTimeout { - t.Errorf("validator %q timeout %v must be < facade ValidationOperationTimeout %v "+ - "(else the orchestration cap preempts the per-check structured result)", - v.Name, v.Timeout, defaults.ValidationOperationTimeout) + timeout := v.Timeout + if timeout == 0 { + timeout = defaults.ValidatorDefaultTimeout + } + // The facade budget must exceed the deadline Kubernetes actually + // enforces, not just the catalog value — the Job now outlives the check + // budget by ValidatorJobDeadlineHeadroom. + enforced := v1.JobDeadlineFor(timeout) + if enforced >= defaults.ValidationOperationTimeout { + t.Errorf("%s: rendered Job deadline %v must stay under ValidationOperationTimeout (%v)", + v.Name, enforced, defaults.ValidationOperationTimeout) } } } @@ -81,6 +88,58 @@ func TestExpectedResourcesCatalogEnvelope(t *testing.T) { } } +// TestRenderedJobDeadlineExceedsOrchestratorWait pins the ordering that keeps a +// timed-out validator's logs readable: the check's own context expires first, +// the orchestrator is still waiting when it does, and the Job's +// activeDeadlineSeconds — the only clock that DELETES the pod — is last. +// Issue #2473 was this ordering collapsing into a three-way tie. +func TestRenderedJobDeadlineExceedsOrchestratorWait(t *testing.T) { + catalog, err := LoadWithDataProvider(context.Background(), nil, "", "") + if err != nil { + t.Fatalf("Load() failed: %v", err) + } + if len(catalog.Validators) == 0 { + t.Fatal("catalog has no validators — invariant cannot be verified") + } + for _, entry := range catalog.Validators { + t.Run(entry.Name, func(t *testing.T) { + plan, buildErr := v1.BuildJobPlan(entry, "run", "ns", "v", "c", "sa", nil, nil, nil, "", "", nil) + if buildErr != nil { + t.Fatalf("BuildJobPlan(%s) failed: %v", entry.Name, buildErr) + } + + checkTimeout := entry.Timeout + if checkTimeout == 0 { + checkTimeout = defaults.ValidatorDefaultTimeout + } + orchestratorWait := int64((checkTimeout + defaults.ValidatorWaitBuffer).Seconds()) + + if plan.CheckTimeout != int64(checkTimeout.Seconds()) { + t.Errorf("CheckTimeout = %d, want %d", plan.CheckTimeout, int64(checkTimeout.Seconds())) + } + if plan.JobDeadline <= orchestratorWait { + t.Errorf("JobDeadline (%ds) must exceed the orchestrator wait (%ds); "+ + "otherwise the Job controller deletes the pod before its logs are read", + plan.JobDeadline, orchestratorWait) + } + + // Both renderers must carry the same deadline, or server-side apply + // and the typed path diverge. Production uses the apply path + // (pkg/validator/job/deployer.go RenderPlanToApplyConfig). + typed := v1.RenderPlan(plan) + if typed.Spec.ActiveDeadlineSeconds == nil || *typed.Spec.ActiveDeadlineSeconds != plan.JobDeadline { + t.Errorf("RenderPlan ActiveDeadlineSeconds = %v, want %d", + typed.Spec.ActiveDeadlineSeconds, plan.JobDeadline) + } + applied := v1.RenderPlanToApplyConfig(plan, "job-name") + if applied.Spec.ActiveDeadlineSeconds == nil || *applied.Spec.ActiveDeadlineSeconds != plan.JobDeadline { + t.Errorf("RenderPlanToApplyConfig ActiveDeadlineSeconds = %v, want %d", + applied.Spec.ActiveDeadlineSeconds, plan.JobDeadline) + } + }) + } +} + func TestLoadEmbeddedCatalog(t *testing.T) { catalog, err := LoadWithDataProvider(context.Background(), nil, "", "") if err != nil { diff --git a/pkg/validator/v1/job_plan.go b/pkg/validator/v1/job_plan.go index c3b2312bc7..d281d6263a 100644 --- a/pkg/validator/v1/job_plan.go +++ b/pkg/validator/v1/job_plan.go @@ -16,6 +16,7 @@ package v1 import ( "strings" + "time" "github.com/NVIDIA/aicr/pkg/defaults" "github.com/NVIDIA/aicr/pkg/recipe" @@ -71,8 +72,14 @@ type JobPlan struct { // Resources are container resource requirements Resources corev1.ResourceRequirements - // Timeout is the maximum execution time (Job activeDeadlineSeconds) - Timeout int64 + // CheckTimeout is the budget the check itself is given, published to the + // container as AICR_CHECK_TIMEOUT. + CheckTimeout int64 + + // JobDeadline is the Job's activeDeadlineSeconds. It exceeds CheckTimeout + // by defaults.ValidatorJobDeadlineHeadroom so the check always terminates + // itself first and its pod survives for log extraction. + JobDeadline int64 // ServiceAccount is the Kubernetes ServiceAccount name ServiceAccount string @@ -180,6 +187,13 @@ func Plan( return plans, nil } +// JobDeadlineFor returns the Job activeDeadlineSeconds a given check timeout +// renders to. Single source for the derivation so the renderer and any code +// reporting the enforced deadline cannot drift apart. +func JobDeadlineFor(checkTimeout time.Duration) time.Duration { + return checkTimeout + defaults.ValidatorJobDeadlineHeadroom +} + // BuildJobPlan creates a JobPlan from a validator entry. // Exposed as public for verification and testing purposes. // @@ -258,7 +272,8 @@ func BuildJobPlan( Volumes: volumes, VolumeMounts: volumeMounts, Resources: resources, - Timeout: int64(timeout.Seconds()), + CheckTimeout: int64(timeout.Seconds()), + JobDeadline: int64(JobDeadlineFor(timeout).Seconds()), ServiceAccount: serviceAccount, Tolerations: []corev1.Toleration{{Operator: corev1.TolerationOpExists}}, ImagePullSecrets: imagePullSecrets, @@ -288,7 +303,7 @@ func RenderPlan(plan JobPlan) *batchv1.Job { Labels: plan.Labels, }, Spec: batchv1.JobSpec{ - ActiveDeadlineSeconds: &plan.Timeout, + ActiveDeadlineSeconds: &plan.JobDeadline, BackoffLimit: int32Ptr(0), TTLSecondsAfterFinished: int32Ptr(int32(defaults.JobTTLAfterFinished.Seconds())), Template: corev1.PodTemplateSpec{ @@ -398,7 +413,7 @@ func RenderPlanToApplyConfig(plan JobPlan, jobName string) *applybatchv1.JobAppl return applybatchv1.Job(jobName, plan.Namespace). WithLabels(plan.Labels). WithSpec(applybatchv1.JobSpec(). - WithActiveDeadlineSeconds(plan.Timeout). + WithActiveDeadlineSeconds(plan.JobDeadline). WithBackoffLimit(0). WithTTLSecondsAfterFinished(int32(defaults.JobTTLAfterFinished.Seconds())). WithTemplate(applycorev1.PodTemplateSpec(). diff --git a/pkg/validator/v1/job_plan_test.go b/pkg/validator/v1/job_plan_test.go index 1c8238bf4c..9110553d31 100644 --- a/pkg/validator/v1/job_plan_test.go +++ b/pkg/validator/v1/job_plan_test.go @@ -672,7 +672,7 @@ func TestRenderPlan(t *testing.T) { Volumes: []corev1.Volume{{Name: "snapshot"}}, VolumeMounts: []corev1.VolumeMount{{Name: "snapshot", MountPath: "/data"}}, Resources: corev1.ResourceRequirements{}, - Timeout: 300, + JobDeadline: 300, ServiceAccount: "test-sa", Tolerations: []corev1.Toleration{{Operator: corev1.TolerationOpExists}}, ImagePullSecrets: []string{"my-secret"}, @@ -764,7 +764,7 @@ func TestRenderPlanTagOverridePullPolicy(t *testing.T) { Namespace: "ns", Image: tt.image, ImageTagOverride: tt.override, - Timeout: 300, + JobDeadline: 300, } // Typed render path (job_plan.go RenderPlan). @@ -798,7 +798,7 @@ func TestRenderPlanToApplyConfig(t *testing.T) { Volumes: []corev1.Volume{{Name: "snapshot"}}, VolumeMounts: []corev1.VolumeMount{{Name: "snapshot", MountPath: "/data"}}, Resources: corev1.ResourceRequirements{}, - Timeout: 600, + JobDeadline: 600, ServiceAccount: "apply-sa", Tolerations: []corev1.Toleration{{Operator: corev1.TolerationOpExists}}, ImagePullSecrets: []string{"apply-secret"}, @@ -898,7 +898,7 @@ func TestRenderPlanToApplyConfig_EnvAndVolumeTypes(t *testing.T) { }, VolumeMounts: []corev1.VolumeMount{{Name: "configmap-vol", MountPath: "/data"}}, Resources: corev1.ResourceRequirements{}, - Timeout: 300, + JobDeadline: 300, ServiceAccount: "sa", Tolerations: []corev1.Toleration{{Operator: corev1.TolerationOpExists}}, ImagePullSecrets: []string{"secret"}, From 9a2b4f42b536a4495439a181a32a826e6a47c76d Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Tue, 8 Sep 2026 19:06:31 -0700 Subject: [PATCH 03/22] docs(validator): fix stale doc comment on facade-budget test Signed-off-by: Alex Yuskauskas --- pkg/validator/catalog/catalog_test.go | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/pkg/validator/catalog/catalog_test.go b/pkg/validator/catalog/catalog_test.go index 6de1f57de5..d450458434 100644 --- a/pkg/validator/catalog/catalog_test.go +++ b/pkg/validator/catalog/catalog_test.go @@ -30,11 +30,13 @@ import ( "gopkg.in/yaml.v3" ) -// TestCatalogTimeoutsFitFacadeBudget asserts every catalog entry's per-check -// timeout stays below the facade-level ValidationOperationTimeout. Otherwise a -// controller/library caller (which gets that facade deadline when no explicit -// timeout is set) could hit the top-level "context deadline exceeded" before -// the per-check Job reaches its own deadline and emits a structured result. +// TestCatalogTimeoutsFitFacadeBudget asserts every catalog entry's rendered +// Job deadline (CheckTimeout + ValidatorJobDeadlineHeadroom, per +// v1.JobDeadlineFor) stays below the facade-level ValidationOperationTimeout. +// Otherwise a controller/library caller (which gets that facade deadline when +// no explicit timeout is set) could hit the top-level "context deadline +// exceeded" before the per-check Job reaches its own deadline and emits a +// structured result. func TestCatalogTimeoutsFitFacadeBudget(t *testing.T) { catalog, err := LoadWithDataProvider(context.Background(), nil, "", "") if err != nil { From abb42fea8dd286666d5a48294e6b46bb30c67ee2 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Tue, 8 Sep 2026 19:12:50 -0700 Subject: [PATCH 04/22] fix(validator): name both the Job deadline and check budget in timeout results Signed-off-by: Alex Yuskauskas --- pkg/validator/job/deployer_test.go | 7 ++++--- pkg/validator/job/result.go | 22 ++++++++++++---------- pkg/validator/job/result_test.go | 19 ++++++++++++------- 3 files changed, 28 insertions(+), 20 deletions(-) diff --git a/pkg/validator/job/deployer_test.go b/pkg/validator/job/deployer_test.go index 77668160ba..4bfa0e6f1c 100644 --- a/pkg/validator/job/deployer_test.go +++ b/pkg/validator/job/deployer_test.go @@ -150,8 +150,9 @@ func TestDeployJobTimeouts(t *testing.T) { ns := createUniqueNamespace(t) job := deployAndGet(t, NewDeployer(Config{Clientset: testClientset, Factory: testFactory(t, ns), Namespace: ns, RunID: "run1", Entry: testEntry()})) - if job.Spec.ActiveDeadlineSeconds == nil || *job.Spec.ActiveDeadlineSeconds != 120 { - t.Errorf("ActiveDeadlineSeconds = %v, want 120", job.Spec.ActiveDeadlineSeconds) + wantDeadline := int64(v1.JobDeadlineFor(2 * time.Minute).Seconds()) // 120 + 210 = 330 + if job.Spec.ActiveDeadlineSeconds == nil || *job.Spec.ActiveDeadlineSeconds != wantDeadline { + t.Errorf("ActiveDeadlineSeconds = %v, want %d", job.Spec.ActiveDeadlineSeconds, wantDeadline) } if job.Spec.BackoffLimit == nil || *job.Spec.BackoffLimit != 0 { t.Errorf("BackoffLimit = %v, want 0", job.Spec.BackoffLimit) @@ -175,7 +176,7 @@ func TestDeployJobDefaultTimeout(t *testing.T) { entry.Timeout = 0 job := deployAndGet(t, NewDeployer(Config{Clientset: testClientset, Factory: testFactory(t, ns), Namespace: ns, RunID: "run1", Entry: entry})) - expected := int64(defaults.ValidatorDefaultTimeout.Seconds()) + expected := int64(v1.JobDeadlineFor(defaults.ValidatorDefaultTimeout).Seconds()) if job.Spec.ActiveDeadlineSeconds == nil || *job.Spec.ActiveDeadlineSeconds != expected { t.Errorf("ActiveDeadlineSeconds = %v, want %d (default)", job.Spec.ActiveDeadlineSeconds, expected) } diff --git a/pkg/validator/job/result.go b/pkg/validator/job/result.go index 0257c6a855..0d6d1d57f3 100644 --- a/pkg/validator/job/result.go +++ b/pkg/validator/job/result.go @@ -28,6 +28,7 @@ import ( "github.com/NVIDIA/aicr/pkg/errors" "github.com/NVIDIA/aicr/pkg/k8s/pod" "github.com/NVIDIA/aicr/pkg/validator/ctrf" + v1 "github.com/NVIDIA/aicr/pkg/validator/v1" batchv1 "k8s.io/api/batch/v1" corev1 "k8s.io/api/core/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -184,8 +185,9 @@ func (d *Deployer) missingPodOutcome(ctx context.Context, findErr error) (exitCo // (quota or webhook rejection), and one removed externally; asserting // controller deletion would name a false root cause for the other two. return validatorExitFailed, boundTerminationMsg(fmt.Sprintf( - "validator Job did not complete within its %s deadline; no pod remains for it, so its logs are unavailable (Job condition Failed/%s: %s)", - enforcedDeadline(job, d.config.Entry.Timeout), cond.Reason, detail), + "validator Job did not complete within its %s Job deadline (check budget %s); no pod remains for it, so its logs are unavailable (Job condition Failed/%s: %s)", + enforcedDeadline(job, d.config.Entry.Timeout), effectiveTimeout(d.config.Entry.Timeout), + cond.Reason, detail), defaults.ValidatorMaxTerminationMsgBytes) } @@ -347,18 +349,18 @@ func effectiveTimeout(configured time.Duration) time.Duration { // Job's spec.activeDeadlineSeconds — the literal value the Job controller // enforced — so it is preferred whenever the Job could be read and carries it. // -// The fallback re-derives it the way BuildJobPlan does, converting the catalog -// timeout with int64(timeout.Seconds()) before assigning it to -// ActiveDeadlineSeconds (pkg/validator/v1/job_plan.go), so any sub-second -// component is truncated away: a 1500ms entry yields a 1s Job deadline. -// Reporting the raw duration would name a deadline that never existed, and the -// whole point of this message is to describe the Kubernetes state that produced -// the failure. +// The fallback derives the deadline v1.JobDeadlineFor(effectiveTimeout(configured)) +// would have produced — the same value BuildJobPlan renders onto +// ActiveDeadlineSeconds. It is unreachable in practice: the only caller, +// missingPodOutcome, sits behind an `if !ok { return -1, notFound }` guard +// that requires jobFailedCondition to have already succeeded, so job is +// non-nil here only when a live Job was just read with ActiveDeadlineSeconds +// set — both renderers in pkg/validator/v1/job_plan.go always set it. func enforcedDeadline(job *batchv1.Job, configured time.Duration) time.Duration { if job != nil && job.Spec.ActiveDeadlineSeconds != nil { return time.Duration(*job.Spec.ActiveDeadlineSeconds) * time.Second } - return time.Duration(int64(effectiveTimeout(configured).Seconds())) * time.Second + return v1.JobDeadlineFor(effectiveTimeout(configured)) } // waitFailureMessage renders the TerminationMsg for a validator whose container diff --git a/pkg/validator/job/result_test.go b/pkg/validator/job/result_test.go index f353f9e9d4..d5757e6a20 100644 --- a/pkg/validator/job/result_test.go +++ b/pkg/validator/job/result_test.go @@ -27,6 +27,7 @@ import ( "github.com/NVIDIA/aicr/pkg/errors" "github.com/NVIDIA/aicr/pkg/validator/catalog" "github.com/NVIDIA/aicr/pkg/validator/ctrf" + v1 "github.com/NVIDIA/aicr/pkg/validator/v1" batchv1 "k8s.io/api/batch/v1" corev1 "k8s.io/api/core/v1" apierrors "k8s.io/apimachinery/pkg/api/errors" @@ -406,17 +407,21 @@ func TestExtractResultPodNotFoundDeadlineExceeded(t *testing.T) { if result.CTRFStatus() != ctrf.StatusFailed { t.Errorf("CTRFStatus = %q, want %q", result.CTRFStatus(), ctrf.StatusFailed) } - // Asserted for every case, including the unpinned one, which must - // render the same default runPhase applies rather than a bare "0s". - // The deadline the Job actually enforced: BuildJobPlan truncates - // to whole seconds before setting activeDeadlineSeconds. + // The message must name BOTH clocks: the deadline Kubernetes + // enforced (now the Job deadline) and the check's own budget from + // the catalog. Naming only one leaves an operator comparing an 11m30s + // message against an 8m catalog entry. want := tt.timeout if want == 0 { want = defaults.ValidatorDefaultTimeout } - wantTimeout := (time.Duration(int64(want.Seconds())) * time.Second).String() - if !strings.Contains(result.TerminationMsg, wantTimeout) { - t.Errorf("TerminationMsg = %q, want it to name the deadline %s", result.TerminationMsg, wantTimeout) + checkBudget := (time.Duration(int64(want.Seconds())) * time.Second) + wantDeadline := v1.JobDeadlineFor(checkBudget).String() + if !strings.Contains(result.TerminationMsg, wantDeadline) { + t.Errorf("TerminationMsg = %q, want it to name the enforced deadline %s", result.TerminationMsg, wantDeadline) + } + if !strings.Contains(result.TerminationMsg, checkBudget.String()) { + t.Errorf("TerminationMsg = %q, want it to name the check budget %s", result.TerminationMsg, checkBudget) } for _, want := range tt.wantContains { if !strings.Contains(result.TerminationMsg, want) { From de27e167c2608dc5fec76df39c04b362a5717cf2 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Tue, 8 Sep 2026 19:24:38 -0700 Subject: [PATCH 05/22] fix(validator): truncate check budget to whole seconds in timeout message Signed-off-by: Alex Yuskauskas --- pkg/validator/job/result.go | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/pkg/validator/job/result.go b/pkg/validator/job/result.go index 0d6d1d57f3..c305893155 100644 --- a/pkg/validator/job/result.go +++ b/pkg/validator/job/result.go @@ -186,7 +186,7 @@ func (d *Deployer) missingPodOutcome(ctx context.Context, findErr error) (exitCo // controller deletion would name a false root cause for the other two. return validatorExitFailed, boundTerminationMsg(fmt.Sprintf( "validator Job did not complete within its %s Job deadline (check budget %s); no pod remains for it, so its logs are unavailable (Job condition Failed/%s: %s)", - enforcedDeadline(job, d.config.Entry.Timeout), effectiveTimeout(d.config.Entry.Timeout), + enforcedDeadline(job, d.config.Entry.Timeout), truncateToSeconds(effectiveTimeout(d.config.Entry.Timeout)), cond.Reason, detail), defaults.ValidatorMaxTerminationMsgBytes) } @@ -344,6 +344,15 @@ func effectiveTimeout(configured time.Duration) time.Duration { return configured } +// truncateToSeconds drops d's sub-second component. Both activeDeadlineSeconds +// and AICR_CHECK_TIMEOUT (pkg/validator/v1/job_plan.go) are whole-second int64 +// values, so any duration reported alongside them must match that precision — +// otherwise the message names a sub-second component the check was never +// actually granted. +func truncateToSeconds(d time.Duration) time.Duration { + return time.Duration(int64(d.Seconds())) * time.Second +} + // enforcedDeadline is the deadline Kubernetes actually applied, as opposed to // the duration the catalog asked for. The authoritative source is the live // Job's spec.activeDeadlineSeconds — the literal value the Job controller From b7d8ae029567b0328a568c41b7b60005a45ee4e7 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Tue, 8 Sep 2026 19:53:51 -0700 Subject: [PATCH 06/22] fix(validator): report collected failures when the check budget expires Signed-off-by: Alex Yuskauskas --- validators/deployment/expected_resources.go | 67 +++++++++++++++---- .../deployment/expected_resources_test.go | 61 +++++++++++++++++ 2 files changed, 115 insertions(+), 13 deletions(-) diff --git a/validators/deployment/expected_resources.go b/validators/deployment/expected_resources.go index 5c3f9d386a..f892b08c64 100644 --- a/validators/deployment/expected_resources.go +++ b/validators/deployment/expected_resources.go @@ -196,6 +196,14 @@ func pollUntilStable(ctx *validators.Context, label string, probe func() error, // checkExpectedResources verifies that all expected Kubernetes resources declared // in the validation's componentRefs exist and are healthy in the live cluster. +// +// Budget exhaustion NEVER returns early: it records the stage in +// budgetExhausted, marks undispatched work, prints the accumulated failures, +// and fails closed (issue #2473). The remaining early returns — a Helm render +// failure at gatedHealthCheckSuppressed, a resource-fetcher construction +// failure, and the RDMA fabric-resource derivation — are hard errors that +// carry their own structured cause and produce no partial failure list worth +// printing, so they still return directly. func checkExpectedResources(ctx *validators.Context) error { if ctx.ValidationInput == nil { return errors.New(errors.ErrCodeInvalidRequest, "validation is not available") @@ -216,6 +224,12 @@ func checkExpectedResources(ctx *validators.Context) error { var firstStructuredErr error enabledRefs := enabledComponentRefs(ctx.ValidationInput.ComponentRefs) + // budgetExhausted names the stage that ran out of deadline, empty when the + // check completed its work. It is deliberately NOT an early return: the + // accumulated failures are the diagnosis, and returning before the + // reporting block below is what made issue #2473 undiagnosable. + var budgetExhausted string + failures = append(failures, verifyNamespacesActive(ctx, enabledRefs)...) // When both ExpectedResources and HealthCheckAsserts are populated on @@ -235,11 +249,12 @@ func checkExpectedResources(ctx *validators.Context) error { // check ctx.Done() in long-running operations and loops". select { case <-ctx.Ctx.Done(): - return errors.Wrap(errors.ErrCodeTimeout, - "deployment validation canceled during expected-resources iteration", - ctx.Ctx.Err()) + budgetExhausted = "expected-resources iteration" default: } + if budgetExhausted != "" { + break + } if ref.HealthCheckAsserts != "" { // The registry-declared static assert cannot see value gates, so on a // component whose effective values suppress the Skyhook CR the assert @@ -282,18 +297,20 @@ func checkExpectedResources(ctx *validators.Context) error { firstStructuredErr = gpuStructuredErr } - if len(chainsawAsserts) > 0 { + if len(chainsawAsserts) > 0 && budgetExhausted == "" { // Bail out before paying chainsaw startup cost if the caller // already canceled. chainsaw.Run honors ctx mid-flight too, // but a short-circuit here skips fetcher construction and // log noise on a doomed run. select { case <-ctx.Ctx.Done(): - return errors.Wrap(errors.ErrCodeTimeout, - "deployment validation canceled before chainsaw dispatch", - ctx.Ctx.Err()) + budgetExhausted = "chainsaw dispatch" default: } + } + if budgetExhausted != "" { + failures = markUndispatched(failures, chainsawAsserts, budgetExhausted) + } else if len(chainsawAsserts) > 0 { slog.Info("running health check assertions", "components", len(chainsawAsserts)) fetcher, fetcherErr := buildResourceFetcher(ctx) if fetcherErr != nil { @@ -331,12 +348,23 @@ func checkExpectedResources(ctx *validators.Context) error { for _, f := range failures { fmt.Printf(" %s\n", f) } - // Prefer the first structured error (e.g., - // ErrCodeInvalidRequest from a registry assert that violated - // the read-only allowlist) over the generic ErrCodeNotFound - // summary so downstream catalog/CLI surfaces classify the - // failure correctly. The human-readable failures list is still - // printed above for operator visibility. + } + + // Fail closed BEFORE the healthy return: an unfinished run is not a passing + // run, and with no collected failures the old code fell through to + // "All deployment resources ... are healthy" (issue #2473). + if budgetExhausted != "" { + return errors.Wrap(errors.ErrCodeTimeout, + fmt.Sprintf("deployment validation budget exhausted during %s with %d issue(s) collected", + budgetExhausted, len(failures)), + ctx.Ctx.Err()) + } + + if len(failures) > 0 { + // Prefer the first structured error (e.g., ErrCodeInvalidRequest from a + // registry assert that violated the read-only allowlist) over the + // generic ErrCodeNotFound summary so downstream catalog/CLI surfaces + // classify the failure correctly. if firstStructuredErr != nil { return firstStructuredErr } @@ -359,6 +387,19 @@ func enabledComponentRefs(refs []recipe.ComponentRef) []recipe.ComponentRef { return enabled } +// markUndispatched appends a not-evaluated line for every assert that was +// queued but never handed to chainsaw. Reporting them explicitly is what stops +// a truncated run from reading as a mostly-healthy cluster: the operator sees +// which components carry no verdict rather than inferring their absence means +// "fine". +func markUndispatched(failures []string, asserts []chainsaw.ComponentAssert, stage string) []string { + for _, a := range asserts { + failures = append(failures, fmt.Sprintf( + "[chainsaw] %s: not evaluated — budget exhausted during %s", a.Name, stage)) + } + return failures +} + func verifyNamespacesActive(ctx *validators.Context, refs []recipe.ComponentRef) []string { var failures []string seen := make(map[string]bool, len(refs)) diff --git a/validators/deployment/expected_resources_test.go b/validators/deployment/expected_resources_test.go index 91ae41aa91..ae03a5b2cb 100644 --- a/validators/deployment/expected_resources_test.go +++ b/validators/deployment/expected_resources_test.go @@ -17,9 +17,12 @@ package main import ( "context" stderrors "errors" + "slices" "strings" "testing" + "github.com/NVIDIA/aicr/pkg/chainsaw" + "github.com/NVIDIA/aicr/pkg/errors" "github.com/NVIDIA/aicr/pkg/recipe" v1 "github.com/NVIDIA/aicr/pkg/validator/v1" "github.com/NVIDIA/aicr/validators" @@ -1722,3 +1725,61 @@ func TestGatedHealthCheckSuppressed(t *testing.T) { } }) } + +// TestCheckExpectedResourcesFailsClosedOnExhaustedBudget is the regression test +// for issue #2473's second half: a check whose budget expires must not report a +// healthy verdict. Before the fix the ctx.Done() branches returned before the +// reporting block, and with no collected failures the function fell through to +// "All deployment resources ... are healthy" and returned nil. +func TestCheckExpectedResourcesFailsClosedOnExhaustedBudget(t *testing.T) { + t.Parallel() + + ctx := newDeploymentTestContext(t, nil, nil, []recipe.ComponentRef{ + {Name: "app-component", Namespace: "app-ns"}, + }) + canceled, cancel := context.WithCancel(context.Background()) + cancel() // budget already spent before the first component is examined + ctx.Ctx = canceled + + err := checkExpectedResources(ctx) + if err == nil { + t.Fatal("checkExpectedResources returned nil on an exhausted budget; it must fail closed") + } + if !stderrors.Is(err, errors.New(errors.ErrCodeTimeout, "")) { + t.Errorf("error = %v, want ErrCodeTimeout", err) + } + if !strings.Contains(err.Error(), "budget exhausted") { + t.Errorf("error = %q, want it to name budget exhaustion", err.Error()) + } +} + +// TestMarkUndispatched proves a component queued for chainsaw but never +// dispatched is reported as not evaluated rather than silently dropped — +// otherwise an operator reads a short failure list and concludes the rest of +// the cluster is fine. +// +// Unit-tested against the helper rather than through checkExpectedResources: +// reaching that path in an integration test needs a context that is live while +// the enabledRefs loop queues asserts and dead by the chainsaw guard a few +// statements later, which is not deterministically arrangeable. +func TestMarkUndispatched(t *testing.T) { + t.Parallel() + + got := markUndispatched( + []string{"[expectedResources] existing failure"}, + []chainsaw.ComponentAssert{{Name: "gpu-operator"}, {Name: "network-operator"}}, + "chainsaw dispatch", + ) + + if len(got) != 3 { + t.Fatalf("got %d failures, want 3 (1 pre-existing + 2 undispatched)", len(got)) + } + for _, want := range []string{ + "[chainsaw] gpu-operator: not evaluated — budget exhausted during chainsaw dispatch", + "[chainsaw] network-operator: not evaluated — budget exhausted during chainsaw dispatch", + } { + if !slices.Contains(got, want) { + t.Errorf("failures %q missing %q", got, want) + } + } +} From 7af041c069f1ba3de0be418134bf5a916bb9eabc Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Wed, 9 Sep 2026 09:11:55 -0700 Subject: [PATCH 07/22] docs(validator): correct expected-resources budget-exhaustion comment Signed-off-by: Alex Yuskauskas --- validators/deployment/expected_resources.go | 17 ++++++++++------- 1 file changed, 10 insertions(+), 7 deletions(-) diff --git a/validators/deployment/expected_resources.go b/validators/deployment/expected_resources.go index f892b08c64..e0111fe388 100644 --- a/validators/deployment/expected_resources.go +++ b/validators/deployment/expected_resources.go @@ -197,13 +197,16 @@ func pollUntilStable(ctx *validators.Context, label string, probe func() error, // checkExpectedResources verifies that all expected Kubernetes resources declared // in the validation's componentRefs exist and are healthy in the live cluster. // -// Budget exhaustion NEVER returns early: it records the stage in -// budgetExhausted, marks undispatched work, prints the accumulated failures, -// and fails closed (issue #2473). The remaining early returns — a Helm render -// failure at gatedHealthCheckSuppressed, a resource-fetcher construction -// failure, and the RDMA fabric-resource derivation — are hard errors that -// carry their own structured cause and produce no partial failure list worth -// printing, so they still return directly. +// The two ctx.Done() checks (expected-resources iteration, chainsaw dispatch) +// never return early: they record the stage in budgetExhausted, mark +// undispatched work, print the accumulated failures, and fail closed (issue +// #2473). gatedHealthCheckSuppressed and buildResourceFetcher still return +// directly on error — both are hard errors, not budget-exhaustion handling. +// gatedHealthCheckSuppressed's error can itself be cancellation-induced (it +// threads ctx.Ctx into a Helm render), and that path discards whatever +// failures were already collected under an ErrCodeInternal wrap rather than +// the fail-closed ErrCodeTimeout above — a known gap, deliberately out of +// scope here. func checkExpectedResources(ctx *validators.Context) error { if ctx.ValidationInput == nil { return errors.New(errors.ErrCodeInvalidRequest, "validation is not available") From b384e7d115484e35415d4607f38d2638e2fd0972 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Wed, 9 Sep 2026 09:29:40 -0700 Subject: [PATCH 08/22] perf(validator): probe GPU readiness signals concurrently Signed-off-by: Alex Yuskauskas --- validators/deployment/expected_resources.go | 62 +++++++++++++++---- .../deployment/expected_resources_test.go | 34 ++++++++++ 2 files changed, 85 insertions(+), 11 deletions(-) diff --git a/validators/deployment/expected_resources.go b/validators/deployment/expected_resources.go index e0111fe388..45be532987 100644 --- a/validators/deployment/expected_resources.go +++ b/validators/deployment/expected_resources.go @@ -470,24 +470,64 @@ func verifyGPUReadinessSignals(ctx *validators.Context, refs []recipe.ComponentR } } + // Build the probe list in a FIXED order. capture() below is applied to the + // results in that same order after the fan-out joins, so firstStructured + // precedence is identical to the previous serial implementation. + var probes []func() error + if ref, ok := findEnabledComponent(refs, nodewrightCustomizationsComponent); ok { - capture(verifyNodewrightReady(ctx, ref)) + // Warm ctx.DynamicClient before the fan-out: getDynamicClient writes it + // on the SHARED Context, which is not safe from a goroutine. Only the + // nodewright probe reaches it, so warming it only when that component is + // enabled keeps Contexts without a RESTConfig (the RDMA dispatch tests) + // off this path entirely. A failure here is deliberately ignored — the + // probe calls getDynamicClient again and surfaces the identical error, + // and that call returns before the write, so no race is introduced. + _, _ = getDynamicClient(ctx) + probes = append(probes, func() error { return verifyNodewrightReady(ctx, ref) }) } if ref, ok := findEnabledComponent(refs, draDriverComponent); ok { - capture(verifyDRAKubeletPluginReady(ctx, ref.Namespace)) + probes = append(probes, func() error { return verifyDRAKubeletPluginReady(ctx, ref.Namespace) }) } if ref, ok := findEnabledComponent(refs, networkOperatorComponent); ok && recipeDeclaresRDMAFabric(ref) { - // The polled resource is derived from the recipe's own NicClusterPolicy - // manifest (rdma/hca_shared_devices_a on AKS, nvidia.com/mlnxnics on OKE) - // so the gate waits for exactly what this recipe's fabric advertises. A - // derivation failure fails the gate closed — never "skip the fabric". - if fabricResource, ferr := rdmaFabricResource(ctx.Ctx, ref); ferr != nil { - capture(ferr) - } else { - capture(verifyRDMAFabricReady(ctx, fabricResource)) - } + probes = append(probes, func() error { + // The polled resource is derived from the recipe's own + // NicClusterPolicy manifest (rdma/hca_shared_devices_a on AKS, + // nvidia.com/mlnxnics on OKE) so the gate waits for exactly what + // this recipe's fabric advertises. A derivation failure fails the + // gate closed — never "skip the fabric". + fabricResource, ferr := rdmaFabricResource(ctx.Ctx, ref) + if ferr != nil { + return ferr + } + return verifyRDMAFabricReady(ctx, fabricResource) + }) + } + + // Plain Group, not WithContext: every probe takes *validators.Context and + // reads ctx.Ctx directly (pollUntilStable), so a derived gctx would be built + // and discarded — the same reasoning as the Skyhook-status/taint-scan + // errgroup fan-out inside verifyNodewrightReady's own poll probe elsewhere + // in this file. Each goroutine writes its result into its own slice index + // and always returns nil, so one unhealthy signal never stops the others + // from running, and results are read back in fixed index order after + // Wait() — never in completion order. + results := make([]error, len(probes)) + g := new(errgroup.Group) + for i, probe := range probes { + g.Go(func() error { + results[i] = probe() + return nil + }) + } + if err := g.Wait(); err != nil { + return nil, errors.Wrap(errors.ErrCodeInternal, "gpu readiness fan-out failed", err) + } + + for _, err := range results { + capture(err) } return failures, firstStructured diff --git a/validators/deployment/expected_resources_test.go b/validators/deployment/expected_resources_test.go index ae03a5b2cb..b489ce6a4d 100644 --- a/validators/deployment/expected_resources_test.go +++ b/validators/deployment/expected_resources_test.go @@ -1033,6 +1033,40 @@ func TestIsRuntimeRequiredTaint(t *testing.T) { } } +// TestVerifyGPUReadinessSignalsPreservesOrderConcurrently pins the two +// properties concurrency must not break: every signal reports (one failure never +// truncates its siblings), and failures come back in the fixed nodewright → DRA +// → RDMA order the firstStructuredErr precedence depends on. +func TestVerifyGPUReadinessSignalsPreservesOrderConcurrently(t *testing.T) { + t.Parallel() + + refs := []recipe.ComponentRef{ + {Name: nodewrightCustomizationsComponent, Namespace: "skyhook", ManifestFiles: []string{testNodewrightManifest}}, + {Name: draDriverComponent, Namespace: "nvidia-dra-driver"}, + } + // The Nodewright GroupVersion must be registered (extraRegistered) or the + // CRD-not-registered skip (#607) returns nil before the signal ever fails — + // this proves both signals report, not just that one CRD is absent. + ctx := newDeploymentTestContextWithDiscovery(t, nil, nil, []schema.GroupVersion{nodewrightGVR.GroupVersion()}, nil, refs) + canceled, cancel := context.WithCancel(context.Background()) + cancel() // force every probe's poll loop to exit on its first iteration + ctx.Ctx = canceled + + failures, firstStructured := verifyGPUReadinessSignals(ctx, refs) + if len(failures) != 2 { + t.Fatalf("got %d failures, want 2 — every enabled signal must report", len(failures)) + } + if !strings.Contains(failures[0], "Nodewright") { + t.Errorf("failures[0] = %q, want the nodewright signal first", failures[0]) + } + // firstStructuredErr precedence is fixed-order, not completion-order: it + // must resolve to the nodewright signal (index 0) even though both probes + // ran concurrently and either could have finished first. + if firstStructured == nil || firstStructured.Error() != failures[0] { + t.Errorf("firstStructured = %v, want it to match failures[0] (%q)", firstStructured, failures[0]) + } +} + func stringSlicesEqual(a, b []string) bool { if len(a) != len(b) { return false From 30ea246bfcf4b96f94bf9710c19c54e91262ce81 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Wed, 9 Sep 2026 10:24:48 -0700 Subject: [PATCH 09/22] docs(validator): describe the Job-deadline headroom ordering Signed-off-by: Alex Yuskauskas --- docs/contributor/validator.md | 20 ++++++----- docs/design/002-validatorv2-adr.md | 34 +++++++++++++------ docs/integrator/validator-extension.md | 2 +- docs/user/validation.md | 4 +-- pkg/defaults/timeouts.go | 12 ++++--- pkg/validator/job/deployer_test.go | 3 +- pkg/validator/v1/README.md | 6 ++-- pkg/validator/v1/catalog.go | 3 +- recipes/validators/README.md | 2 +- recipes/validators/catalog.yaml | 21 +++++++----- validators/conformance/consts.go | 26 ++++++++------ validators/deployment/expected_resources.go | 27 ++++++++------- .../expected_resources_rdma_test.go | 16 +++++---- 13 files changed, 107 insertions(+), 69 deletions(-) diff --git a/docs/contributor/validator.md b/docs/contributor/validator.md index 7979f17c03..43ec20ac3c 100644 --- a/docs/contributor/validator.md +++ b/docs/contributor/validator.md @@ -1266,14 +1266,18 @@ but a readiness test copied from a validator check (`assert: 5m`) is now capped at the gate's 2m per evaluation rather than overrunning it. The `expected-resources` catalog timeout (8m in -`recipes/validators/catalog.yaml`) is the **outer** envelope. It must -exceed the longest in-tree `assert` value plus headroom for -pre-chainsaw work, chainsaw teardown, and log flush -(`defaults.JobEnvelopeMargin`). If assert runs too close to that -catalog deadline, the Job can SIGKILL the pod before chainsaw reports -the failing step — operators see truncated output instead of a useful -failure. Raise the catalog `timeout` in tandem when you need a longer -assert budget (`TestExpectedResourcesCatalogEnvelope` guards this). +`recipes/validators/catalog.yaml`) is the **outer** envelope for the +check's own budget (`AICR_CHECK_TIMEOUT`). It must exceed the longest +in-tree `assert` value plus headroom for pre-chainsaw work, chainsaw +teardown, and log flush (`defaults.JobEnvelopeMargin`). If assert runs +too close to that catalog deadline, the check's own context can expire +before chainsaw reports the failing step — operators see truncated +output instead of a useful failure. The Job's `activeDeadlineSeconds` +(this catalog timeout plus `defaults.ValidatorJobDeadlineHeadroom`) is +a separate, later backstop and no longer the deadline this margin +protects against. Raise the catalog `timeout` in tandem when you need +a longer assert budget (`TestExpectedResourcesCatalogEnvelope` guards +this). ## Constraint evaluation algorithm diff --git a/docs/design/002-validatorv2-adr.md b/docs/design/002-validatorv2-adr.md index 758095a2e3..cd7b1c1b7d 100644 --- a/docs/design/002-validatorv2-adr.md +++ b/docs/design/002-validatorv2-adr.md @@ -110,7 +110,8 @@ Every validator container: Each validator runs as a K8s Job with: - `backoffLimit: 0` — no retries -- `activeDeadlineSeconds` — from catalog `timeout` +- `activeDeadlineSeconds` — catalog `timeout` plus `defaults.ValidatorJobDeadlineHeadroom`, + so the check's own budget always expires first (see Timeout and Termination below) - `terminationGracePeriodSeconds: 30` — time between SIGTERM and SIGKILL - `ttlSecondsAfterFinished: 3600` — 1 hour retention for debugging - `restartPolicy: Never` @@ -143,17 +144,30 @@ Created once per run via Server-Side Apply, cleaned up at end. ### Timeout and Termination -Three independent timeout layers protect against hangs: +Four timeout layers protect against hangs. The first three are ordered so the +check's own budget is always the tightest — the ordering that closes issue +#2473 (see below): -1. **Job `activeDeadlineSeconds`** (from catalog): K8s sends SIGTERM, then SIGKILL - after `terminationGracePeriodSeconds` (30s). Pod logs and termination message - remain available after termination. +1. **Check budget** (catalog `timeout`, published as `AICR_CHECK_TIMEOUT`): the + validator's own parent context. A well-behaved check cancels and exits on + this deadline before Kubernetes ever intervenes. -2. **Orchestrator wait timeout** (catalog timeout + 30s buffer): If the Job hasn't - reached a terminal state, the orchestrator captures whatever logs/status are - available and moves to the next validator. +2. **Orchestrator wait timeout** (catalog timeout + `defaults.ValidatorWaitBuffer`, + 2m30s): if the Job hasn't reached a terminal state by then, the orchestrator + captures whatever logs/status are available and moves to the next validator. -3. **Parent context timeout** (CLI flag): Cancels the entire phase if exceeded. +3. **Job `activeDeadlineSeconds`** (catalog timeout + `defaults.ValidatorJobDeadlineHeadroom`, + 3m30s): K8s sends SIGTERM, then SIGKILL after `terminationGracePeriodSeconds` (30s), + as a backstop for a check that never exits on its own. Because the headroom keeps + this clock behind clocks 1 and 2, a self-terminated pod is no longer *active* by + the time this deadline could fire, and the Job controller's `deleteActivePods` + only deletes active pods — so the pod survives, `Failed`, with its logs and + termination message intact for extraction. Before this ordering existed, all + three clocks shared one catalog value and the Job's deadline — timed from Job + creation, ahead of the check's own deadline, timed from container start — fired + first and deleted the still-running pod, which is exactly what #2473 reported. + +4. **Parent context timeout** (CLI flag): Cancels the entire phase if exceeded. On any timeout, the orchestrator always attempts log capture with a fresh `context.Background()` context before cleanup, ensuring partial results are never @@ -194,7 +208,7 @@ ValidateAll(ctx, recipe, snapshot) │ ├── For each validator (sequentially): │ │ ├── Deploy Job │ │ ├── Stream stderr (background, for live progress) -│ │ ├── WaitForCompletion(timeout + 30s buffer) +│ │ ├── WaitForCompletion(timeout + ValidatorWaitBuffer) │ │ ├── ExtractResult() — exit code, termination msg, stdout │ │ ├── Add to CTRF report │ │ └── CleanupJob() unless --no-cleanup diff --git a/docs/integrator/validator-extension.md b/docs/integrator/validator-extension.md index bca946d426..225931d7dd 100644 --- a/docs/integrator/validator-extension.md +++ b/docs/integrator/validator-extension.md @@ -244,7 +244,7 @@ ENTRYPOINT ["/check.sh"] - Must run as non-root (validator Jobs use `runAsNonRoot: true`) - Must handle the mounted data paths (`/data/snapshot/`, `/data/validation/`) -- Should respect timeout — the Job has `activeDeadlineSeconds` set from the catalog entry +- Should self-terminate within the catalog `timeout` (published as `AICR_CHECK_TIMEOUT`) rather than rely on the Job — the Job's `activeDeadlineSeconds` is set to the catalog entry plus a fixed headroom, as a backstop for a check that never exits on its own - Should write meaningful evidence to stdout for the CTRF report - Must use explicit image tags (not `:latest`) for reproducibility in external catalogs diff --git a/docs/user/validation.md b/docs/user/validation.md index f56cfea3c1..24c892d6e0 100644 --- a/docs/user/validation.md +++ b/docs/user/validation.md @@ -876,8 +876,8 @@ error codes (see [`pkg/errors/exitcode.go`](https://github.com/NVIDIA/aicr/blob/ > **Important:** two subtleties to be aware of when gating a pipeline on exit code: > -> 1. Both `failed` and `other` are blocking. A phase whose status is `other` — the check produced no usable verdict, e.g. a crash, an OOM, or a Job that failed for a non-deadline reason with its pod already gone — drives the same non-zero exit as `failed` — an inconclusive check fails closed rather than passing silently. `--fail-on-error=false` suppresses **both** result-driven exits (the run reports the outcomes in the CTRF report and exits 0); it does not distinguish `failed` from `other`. A validator Job killed on `activeDeadlineSeconds` normally reports `failed` rather than `other`: its terminal `Failed/DeadlineExceeded` condition is a verdict, so the result names the deadline instead of the missing pod. One narrow exception remains — the CLI waits `activeDeadlineSeconds` plus a 30s buffer for the Job to become terminal, and that buffer equals the validator pod's termination grace period, so a validator that consumes its full grace can exhaust the wait before the condition is stamped. Such a run falls back to the CLI-wait path and still reports `other`. -> 2. Exit 5 is narrower than it sounds. A timeout **inside** a check's own logic (DynamoGraphDeployment not ready, inference endpoint never healthy, AIPerf Job pod-wait deadline) surfaces as a failed phase, not as a structured `ErrCodeTimeout`, so the CLI exits **8**. So does a per-validator wait deadline: `runPhase` hands that error to the timeout handler and records the outcome as a check result rather than propagating it, which is the same path the full-grace exception in note 1 takes. The rule, rather than a list of sources: exit 5 applies whenever an `ErrCodeTimeout` reaches the top-level CLI. A timeout that is converted into a check result instead — whether raised inside a check or by a per-validator wait — surfaces as exit 8. +> 1. Both `failed` and `other` are blocking. A phase whose status is `other` — the check produced no usable verdict, e.g. a crash, an OOM, or a Job that failed for a non-deadline reason with its pod already gone — drives the same non-zero exit as `failed` — an inconclusive check fails closed rather than passing silently. `--fail-on-error=false` suppresses **both** result-driven exits (the run reports the outcomes in the CTRF report and exits 0); it does not distinguish `failed` from `other`. A validator Job killed on `activeDeadlineSeconds` normally reports `failed` rather than `other`: its terminal `Failed/DeadlineExceeded` condition is a verdict, so the result names the deadline instead of the missing pod. One narrow exception remains — the CLI waits the catalog timeout plus `ValidatorWaitBuffer` (2m30s) for the Job to become terminal, a window that is deliberately shorter than the Job's own `activeDeadlineSeconds` (catalog timeout plus `ValidatorJobDeadlineHeadroom`, 3m30s), so a validator whose pod is still running when the CLI's wait expires exhausts the wait before the deadline condition is ever stamped. Such a run falls back to the CLI-wait path and still reports `other`. +> 2. Exit 5 is narrower than it sounds. A timeout **inside** a check's own logic (DynamoGraphDeployment not ready, inference endpoint never healthy, AIPerf Job pod-wait deadline) surfaces as a failed phase, not as a structured `ErrCodeTimeout`, so the CLI exits **8**. So does a per-validator wait deadline: `runPhase` hands that error to the timeout handler and records the outcome as a check result rather than propagating it, which is the same path the wait-exhaustion exception in note 1 takes. The rule, rather than a list of sources: exit 5 applies whenever an `ErrCodeTimeout` reaches the top-level CLI. A timeout that is converted into a check result instead — whether raised inside a check or by a per-validator wait — surfaces as exit 8. Scripts that gate on validation outcome should treat **any non-zero code** as failure rather than branching on specific values, and should additionally diff --git a/pkg/defaults/timeouts.go b/pkg/defaults/timeouts.go index fdb4e51f07..25655aafa8 100644 --- a/pkg/defaults/timeouts.go +++ b/pkg/defaults/timeouts.go @@ -146,14 +146,16 @@ const ( // ValidationOperationTimeout is the facade-level upper bound for // Client.ValidateState when the caller's context has no deadline // (controller/library callers; the CLI runs uncapped). It must exceed the - // LARGEST per-check Job timeout so that inner timeout fires first and the + // LARGEST rendered per-check Job deadline (catalog timeout plus + // ValidatorJobDeadlineHeadroom) so that inner timeout fires first and the // run surfaces a structured per-check error rather than the wrapping // context's bare deadline-exceeded. The largest is the inference-perf // catalog timeout (65m, which covers the model-cache populate + cold-start - // benchmark phases), not CheckExecutionTimeout (55m, the fallback when no - // catalog timeout is set). 75m keeps margin above 65m for orchestration - // overhead (snapshot agent, RBAC, namespace setup, cleanup). The - // catalog-vs-facade relationship is asserted in + // benchmark phases) plus the 3m30s headroom, i.e. 68m30s — not + // CheckExecutionTimeout (55m, the fallback when no catalog timeout is + // set). 75m keeps margin above that 68m30s rendered deadline for + // orchestration overhead (snapshot agent, RBAC, namespace setup, + // cleanup). The catalog-vs-facade relationship is asserted in // pkg/validator/catalog/catalog_test.go. ValidationOperationTimeout = 75 * time.Minute diff --git a/pkg/validator/job/deployer_test.go b/pkg/validator/job/deployer_test.go index 4bfa0e6f1c..60edd2d37d 100644 --- a/pkg/validator/job/deployer_test.go +++ b/pkg/validator/job/deployer_test.go @@ -264,7 +264,8 @@ func TestDeployJobEnvVars(t *testing.T) { // AICR_CHECK_TIMEOUT propagates the entry's catalog-level timeout to // validators.checkTimeoutFromEnv so the inner parent context matches - // the Job's ActiveDeadlineSeconds. Value is time.Duration.String(). + // CheckTimeout, not the Job's larger ActiveDeadlineSeconds (which adds + // defaults.ValidatorJobDeadlineHeadroom). Value is time.Duration.String(). timeoutEnv, ok := envMap["AICR_CHECK_TIMEOUT"] if !ok { t.Error("AICR_CHECK_TIMEOUT must be injected") diff --git a/pkg/validator/v1/README.md b/pkg/validator/v1/README.md index 77ee6dec6c..bb28a05218 100644 --- a/pkg/validator/v1/README.md +++ b/pkg/validator/v1/README.md @@ -173,7 +173,8 @@ type JobPlan struct { Volumes []corev1.Volume // snapshot + validation ConfigMaps VolumeMounts []corev1.VolumeMount Resources corev1.ResourceRequirements - Timeout int64 // activeDeadlineSeconds + CheckTimeout int64 // check's own budget; published as AICR_CHECK_TIMEOUT + JobDeadline int64 // activeDeadlineSeconds = CheckTimeout + ValidatorJobDeadlineHeadroom ServiceAccount string Tolerations []corev1.Toleration // forwarded; orchestrator pod is tolerate-all ImagePullSecrets []string @@ -222,7 +223,8 @@ if err != nil { return err } -plan.Timeout = 600 // 10 minutes +plan.CheckTimeout = 600 // 10 minutes +plan.JobDeadline = int64(v1.JobDeadlineFor(10 * time.Minute).Seconds()) // activeDeadlineSeconds plan.Env = append(plan.Env, corev1.EnvVar{Name: "MY_VAR", Value: "x"}) job := v1.RenderPlan(plan) diff --git a/pkg/validator/v1/catalog.go b/pkg/validator/v1/catalog.go index 65d2bb54ef..002a616c52 100644 --- a/pkg/validator/v1/catalog.go +++ b/pkg/validator/v1/catalog.go @@ -90,7 +90,8 @@ type ValidatorEntry struct { Image string `json:"image" yaml:"image"` // Timeout is the maximum execution time for this validator. - // Maps to Job activeDeadlineSeconds. + // Published to the container as AICR_CHECK_TIMEOUT; the Job's + // activeDeadlineSeconds adds defaults.ValidatorJobDeadlineHeadroom on top. Timeout time.Duration `json:"timeout" yaml:"timeout"` // Args are the container arguments. diff --git a/recipes/validators/README.md b/recipes/validators/README.md index 2da65d7f4d..851397cd01 100644 --- a/recipes/validators/README.md +++ b/recipes/validators/README.md @@ -15,7 +15,7 @@ validators: phase: deployment # deployment | performance | conformance description: "Human-readable" # Shown in CTRF report image: ghcr.io/.../img:latest # OCI image reference - timeout: 2m # Job activeDeadlineSeconds + timeout: 2m # Check's own budget (AICR_CHECK_TIMEOUT); activeDeadlineSeconds adds headroom args: ["operator-health"] # Container arguments env: [] # Optional environment variables resources: # Optional (omit for defaults) diff --git a/recipes/validators/catalog.yaml b/recipes/validators/catalog.yaml index 9562670426..f12cab0bf1 100644 --- a/recipes/validators/catalog.yaml +++ b/recipes/validators/catalog.yaml @@ -40,11 +40,14 @@ validators: image: ghcr.io/nvidia/aicr-validators/deployment:latest # Must be strictly > defaults.ChainsawAssertTimeout (6m) + # defaults.JobEnvelopeMargin (60s) so chainsaw has headroom to - # terminate, clean up its temp dir, and flush log output before the - # Job's SIGKILL AND so pre-chainsaw work (helper.VerifyResource - # iteration) can't starve the chainsaw budget. 8m provides 60s for - # cleanup plus another 60s for pre-chainsaw work. The invariant is - # verified by TestExpectedResourcesCatalogEnvelope in + # terminate, clean up its temp dir, and flush log output before this + # check's own AICR_CHECK_TIMEOUT context elapses AND so pre-chainsaw + # work (helper.VerifyResource iteration) can't starve the chainsaw + # budget. 8m provides 60s for cleanup plus another 60s for + # pre-chainsaw work. The Job's activeDeadlineSeconds adds + # defaults.ValidatorJobDeadlineHeadroom (3m30s) on top of this value + # as a separate, later backstop. The invariant is verified by + # TestExpectedResourcesCatalogEnvelope in # pkg/validator/catalog — raising ChainsawAssertTimeout without # raising this in tandem will fail the test. See issue #1220 and # PR #1235 review. @@ -112,9 +115,11 @@ validators: # + AIPerf pod scheduling (5m) + AIPerf benchmark (15m) # = 50m. The 65m timeout = that 50m sum + 15m headroom for inter-phase # overhead (slow registries, K8s API round-trips) and deferred cleanup / - # CTRF-tail work. The Job's activeDeadlineSeconds derives from this value and - # kills the pod only after the ctx has surfaced a clean timeout. Raising the - # model (or disabling the cache) shifts this budget — see the knobs below. + # CTRF-tail work. The Job's activeDeadlineSeconds adds + # defaults.ValidatorJobDeadlineHeadroom (3m30s) on top of this value, so + # it kills the pod only after the ctx has already surfaced a clean + # timeout. Raising the model (or disabling the cache) shifts this + # budget — see the knobs below. timeout: 65m args: ["inference-perf"] # Benchmark tuning knobs (optional). AIPerf warms up before measuring so diff --git a/validators/conformance/consts.go b/validators/conformance/consts.go index bb34c96d13..54e5409e1c 100644 --- a/validators/conformance/consts.go +++ b/validators/conformance/consts.go @@ -101,10 +101,11 @@ const ( // Per-check WORK budgets for the two GPU allocation conformance checks. Each // check bounds all of its resource-creating work — allocation-mode discovery, // namespace/claim/pod creation, pod waits, log collection, and validation — -// to a budget, so that inside the catalog timeout (which becomes the Job's -// activeDeadlineSeconds AND the check context's deadline via -// AICR_CHECK_TIMEOUT) there is always room left for ONE bounded namespace -// cleanup plus scheduling-skew/result-flush margin. +// to a budget, so that inside the catalog timeout (which becomes the check +// context's deadline via AICR_CHECK_TIMEOUT — the Job's activeDeadlineSeconds +// is this value plus defaults.ValidatorJobDeadlineHeadroom) there is always +// room left for ONE bounded namespace cleanup plus scheduling-skew/result- +// flush margin. // secure-accelerator-access applies the budget at entry; dra-support first // settles scoping (pure recipe check, or the standalone read-only presence // probe bounded separately by draProbeTimeout) so skip semantics survive @@ -126,16 +127,19 @@ const ( // resources needing reconciliation — not a validator-wide lifecycle change. // It is not an absolute guarantee: startup skew beyond the margin, or a // SIGKILL, can still cut cleanup off. Leaked per-run namespaces carry the -// gpuTestRunLabel ownership label for external sweeping; broader validator -// lifecycle hardening (signal-aware cancellation, Job-deadline headroom) is -// tracked separately. The fallback-budget-vs-catalog-timeout arithmetic is -// asserted in TestGPUCheckWorkBudgetsFitCatalogTimeouts. +// gpuTestRunLabel ownership label for external sweeping; Job-deadline +// headroom (defaults.ValidatorJobDeadlineHeadroom, #2473) now covers the +// validator-wide lifecycle hardening this note used to defer — the +// remaining gap is signal-aware cancellation. The fallback-budget-vs- +// catalog-timeout arithmetic is asserted in +// TestGPUCheckWorkBudgetsFitCatalogTimeouts. const ( // gpuCheckSkewAndFlushMargin absorbs pod scheduling/startup skew (the // Job's activeDeadlineSeconds clock starts at Job creation; the check - // context's deadline clock starts at process boot, so the context can - // nominally outlive the Job by the skew) and result flushing after - // cleanup. + // context's deadline clock starts at process boot) and result flushing + // after cleanup. defaults.ValidatorJobDeadlineHeadroom now sizes the + // Job's deadline well past this margin, so the Job reliably outlives + // the check context rather than the reverse. gpuCheckSkewAndFlushMargin = time.Minute // gpuCheckCleanupReserve is the slice of the check's remaining deadline diff --git a/validators/deployment/expected_resources.go b/validators/deployment/expected_resources.go index 45be532987..f467c19059 100644 --- a/validators/deployment/expected_resources.go +++ b/validators/deployment/expected_resources.go @@ -1222,22 +1222,25 @@ func verifyRDMAFabricReadyEmit(ctx *validators.Context, fabricResource string, e coverage = cov // Eager disclosure floor: emit the structured coverage once, on the // first observation that actually enumerated an RDMA-candidate node, - // so a cordoned node narrowing the cohort survives even if the Job's - // activeDeadlineSeconds SIGKILLs the process mid-poll before the - // terminal emit runs. The catalog timeout feeds both the Job deadline - // and this poll budget with no margin (pkg/validator/v1/job_plan.go), - // so an exhausted never-ready poll (every RDMA node cordoned for - // maintenance, or a rollout slower than the budget) can be killed at - // the deadline with no terminal emit. parseExtraSentinels keeps the - // LAST valid sentinel, so a clean exit's terminal emit wins and a - // deadline kill leaves this floor as the disclosure of record. + // so a cordoned node narrowing the cohort survives even if the + // process never reaches the terminal emit below. The catalog timeout + // bounds this poll (AICR_CHECK_TIMEOUT); the Job's + // activeDeadlineSeconds now adds defaults.ValidatorJobDeadlineHeadroom + // on top (pkg/validator/v1/job_plan.go), so an exhausted never-ready + // poll (every RDMA node cordoned for maintenance, or a rollout slower + // than the budget) has margin to unwind and reach the terminal emit + // before the Job's SIGKILL. parseExtraSentinels keeps the LAST valid + // sentinel, so a clean exit's terminal emit wins and this floor is + // the disclosure of record only on the rarer path where the process + // is still killed before reaching it. // validated=0: nothing is certified mid-poll. Only the structured // Extra is emitted eagerly (not the stdout enumeration) — the Extra is // the piece that survives redaction into the signed bundle (#1951/ // #1952), and duplicating stdout would spam divergent counts. The - // broader no-margin kill race predates this gate and is tracked - // separately; this closes only the gate's own every-terminal-outcome - // coverage contract. + // broader no-margin kill race (#2473) is now bounded generally by + // defaults.ValidatorJobDeadlineHeadroom; this floor remains + // defense-in-depth for a probe call that blocks past its own + // poll-budget cancellation. if !emittedEarly && cov.total() > 0 { emittedEarly = true emitCoverage(0, cov.total()) diff --git a/validators/deployment/expected_resources_rdma_test.go b/validators/deployment/expected_resources_rdma_test.go index c95e502402..c005dfbfa3 100644 --- a/validators/deployment/expected_resources_rdma_test.go +++ b/validators/deployment/expected_resources_rdma_test.go @@ -204,13 +204,15 @@ func TestVerifyRDMAFabricReady_Poll(t *testing.T) { } // TestVerifyRDMAFabricReady_EagerDisclosureFloor locks the every-terminal-outcome -// coverage contract against the mid-poll SIGKILL race: the catalog timeout feeds -// both the Job's activeDeadlineSeconds and this poll's budget with no margin, so -// a never-ready poll can be killed at the deadline before the terminal emit runs. -// The eager floor must have already emitted the structured coverage — including -// the cordoned node that narrowed the cohort — on the first observation, with -// validated=0 (nothing is certified mid-poll). parseExtraSentinels keeps the last -// valid sentinel, so on a clean exit the terminal emit overwrites the floor. +// coverage contract for the case where the process is killed before reaching +// the terminal emit: the eager floor must have already emitted the structured +// coverage — including the cordoned node that narrowed the cohort — on the +// first observation, with validated=0 (nothing is certified mid-poll). This +// guards the narrower gap left once defaults.ValidatorJobDeadlineHeadroom gave +// the Job's activeDeadlineSeconds margin over this poll's catalog-timeout-bound +// budget (a probe call blocking past its own cancellation, not a deadline +// race). parseExtraSentinels keeps the last valid sentinel, so on a clean exit +// the terminal emit overwrites the floor. func TestVerifyRDMAFabricReady_EagerDisclosureFloor(t *testing.T) { t.Parallel() From 09e13cac06b3e54c399f27ad8d7f8b34c2414387 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Wed, 9 Sep 2026 10:48:05 -0700 Subject: [PATCH 10/22] docs(validator): fix stale activeDeadlineSeconds claim in catalog test doc Signed-off-by: Alex Yuskauskas --- pkg/validator/catalog/catalog_test.go | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/pkg/validator/catalog/catalog_test.go b/pkg/validator/catalog/catalog_test.go index d450458434..cabf67b720 100644 --- a/pkg/validator/catalog/catalog_test.go +++ b/pkg/validator/catalog/catalog_test.go @@ -59,11 +59,12 @@ func TestCatalogTimeoutsFitFacadeBudget(t *testing.T) { } // TestExpectedResourcesCatalogEnvelope asserts the expected-resources -// validator's catalog timeout (which becomes the Job's -// activeDeadlineSeconds) exceeds the inner chainsaw assert timeout by -// enough headroom for graceful chainsaw termination. Without this, -// chainsaw is SIGKILLed mid-cleanup and operators see truncated output. -// See issue #1220. +// validator's catalog timeout (the check's own AICR_CHECK_TIMEOUT budget — +// the Job's activeDeadlineSeconds is this value plus +// ValidatorJobDeadlineHeadroom, see TestRenderedJobDeadlineExceedsOrchestratorWait +// below) exceeds the inner chainsaw assert timeout by enough headroom for +// graceful chainsaw termination. Without this, chainsaw is SIGKILLed +// mid-cleanup and operators see truncated output. See issue #1220. func TestExpectedResourcesCatalogEnvelope(t *testing.T) { catalog, err := LoadWithDataProvider(context.Background(), nil, "", "") if err != nil { From 49e627b6633480e97edd9092619846c1ae743fef Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Wed, 9 Sep 2026 11:16:02 -0700 Subject: [PATCH 11/22] fix(validator): fail closed when GPU readiness exhausts the check budget The chainsaw-dispatch budget probe only fired when chainsawAsserts was non-empty, so a recipe whose enabled refs queued no asserts never recorded exhaustion even when verifyGPUReadinessSignals itself consumed the remaining budget -- exactly the path issue #2473 reported. That let an exhausted run with no collected failures fall through to the healthy return, and one with failures report the wrong error code instead of the fail-closed timeout. Make the probe unconditional and rename the stage label so it reads correctly whether or not any asserts were queued. Also fix the verifyGPUReadinessSignals fan-out's unreachable-but-wrong g.Wait() error branch, which discarded every collected failure into a nil return; match the two sibling fan-outs in the same file that already use "_ = g.Wait()" since goroutines never return an error there. Corrects two stale doc comments in the same function: "two Go-resident deep checks" is now three (nodewright, DRA kubelet-plugin, RDMA fabric), and the checkExpectedResources doc comment now notes that markUndispatched only covers already-queued asserts, not refs the loop never reached. Pins the regression test's collected-failure count so the headline behavior (collected failures survive into the fail-closed report) is actually asserted, not just the error code and message shape. Signed-off-by: Alex Yuskauskas --- validators/deployment/expected_resources.go | 53 ++++++++++--------- .../deployment/expected_resources_test.go | 8 +++ 2 files changed, 37 insertions(+), 24 deletions(-) diff --git a/validators/deployment/expected_resources.go b/validators/deployment/expected_resources.go index f467c19059..f181c596d0 100644 --- a/validators/deployment/expected_resources.go +++ b/validators/deployment/expected_resources.go @@ -197,11 +197,17 @@ func pollUntilStable(ctx *validators.Context, label string, probe func() error, // checkExpectedResources verifies that all expected Kubernetes resources declared // in the validation's componentRefs exist and are healthy in the live cluster. // -// The two ctx.Done() checks (expected-resources iteration, chainsaw dispatch) -// never return early: they record the stage in budgetExhausted, mark -// undispatched work, print the accumulated failures, and fail closed (issue -// #2473). gatedHealthCheckSuppressed and buildResourceFetcher still return -// directly on error — both are hard errors, not budget-exhaustion handling. +// The two ctx.Done() checks (expected-resources iteration, GPU readiness / +// chainsaw dispatch) never return early: they record the stage in +// budgetExhausted, mark undispatched work, print the accumulated failures, +// and fail closed (issue #2473). "Mark undispatched work" covers only the +// chainsaw asserts already queued when the loop broke (via markUndispatched); +// enabledRefs entries the loop never reached produce no line at all. The +// second check is unconditional — it does not require any chainsaw asserts +// to have been queued, since verifyGPUReadinessSignals alone can exhaust the +// budget on a recipe that queued none. gatedHealthCheckSuppressed and +// buildResourceFetcher still return directly on error — both are hard +// errors, not budget-exhaustion handling. // gatedHealthCheckSuppressed's error can itself be cancellation-induced (it // threads ctx.Ctx into a Helm render), and that path discards whatever // failures were already collected under an ErrCodeInternal wrap rather than @@ -300,16 +306,14 @@ func checkExpectedResources(ctx *validators.Context) error { firstStructuredErr = gpuStructuredErr } - if len(chainsawAsserts) > 0 && budgetExhausted == "" { - // Bail out before paying chainsaw startup cost if the caller - // already canceled. chainsaw.Run honors ctx mid-flight too, - // but a short-circuit here skips fetcher construction and - // log noise on a doomed run. - select { - case <-ctx.Ctx.Done(): - budgetExhausted = "chainsaw dispatch" - default: - } + // This probe must run regardless of whether any asserts were queued: + // verifyGPUReadinessSignals above can itself consume the remaining budget + // on a recipe whose enabled refs queued no chainsaw asserts, and skipping + // the check in that case is exactly the fail-open issue #2473 closed + // elsewhere in this function — an exhausted context with zero collected + // failures must still fail closed, not fall through to the healthy return. + if budgetExhausted == "" && ctx.Ctx.Err() != nil { + budgetExhausted = "GPU readiness / chainsaw dispatch" } if budgetExhausted != "" { failures = markUndispatched(failures, chainsawAsserts, budgetExhausted) @@ -431,12 +435,13 @@ func verifyNamespacesActive(ctx *validators.Context, refs []recipe.ComponentRef) return failures } -// verifyGPUReadinessSignals runs the two Go-resident deep checks -// introduced by issue #611. Returns the human-readable failure strings -// plus the first *errors.StructuredError encountered across all checks -// so the caller can propagate the original error code (e.g., -// ErrCodeInternal from a discovery/RBAC failure) instead of flattening -// it into the generic ErrCodeNotFound summary — per PR #1235 review. +// verifyGPUReadinessSignals runs the three Go-resident deep checks (nodewright, +// DRA kubelet-plugin, RDMA fabric) introduced by issue #611. Returns the +// human-readable failure strings plus the first *errors.StructuredError +// encountered across all checks so the caller can propagate the original +// error code (e.g., ErrCodeInternal from a discovery/RBAC failure) instead of +// flattening it into the generic ErrCodeNotFound summary — per PR #1235 +// review. // // Migration disposition (per #1220 plan): // @@ -522,9 +527,9 @@ func verifyGPUReadinessSignals(ctx *validators.Context, refs []recipe.ComponentR return nil }) } - if err := g.Wait(); err != nil { - return nil, errors.Wrap(errors.ErrCodeInternal, "gpu readiness fan-out failed", err) - } + // Goroutines never return an error (results are recorded per-index), so Wait + // only blocks until every probe completes. + _ = g.Wait() for _, err := range results { capture(err) diff --git a/validators/deployment/expected_resources_test.go b/validators/deployment/expected_resources_test.go index b489ce6a4d..8ae7cfe351 100644 --- a/validators/deployment/expected_resources_test.go +++ b/validators/deployment/expected_resources_test.go @@ -1785,6 +1785,14 @@ func TestCheckExpectedResourcesFailsClosedOnExhaustedBudget(t *testing.T) { if !strings.Contains(err.Error(), "budget exhausted") { t.Errorf("error = %q, want it to name budget exhaustion", err.Error()) } + // verifyNamespacesActive runs before the enabledRefs loop and, against the + // nil-kubeObjects fake clientset, produces exactly one NotFound failure for + // app-ns before the loop's own ctx.Done() check trips budgetExhausted. This + // pins that collected failures survive into the fail-closed report rather + // than being discarded — the commit's headline behavior. + if !strings.Contains(err.Error(), "1 issue(s) collected") { + t.Errorf("error = %q, want it to report 1 issue(s) collected", err.Error()) + } } // TestMarkUndispatched proves a component queued for chainsaw but never From 501297a90053087baaaf61ce0ca7cdec3ae2cd52 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Wed, 9 Sep 2026 11:16:14 -0700 Subject: [PATCH 12/22] fix(validator): name the orchestrator wait clock in timeout messages waitFailureMessage rendered "timeout: validator did not complete within ", but WaitForCompletion actually waits catalog timeout + ValidatorWaitBuffer -- a 10m30s wait was reported as an 8m timeout. Since #2473 added Job-deadline headroom, a hung check now routinely expires this orchestrator wait before the Job's own deadline, making the understated message more common. Render both components explicitly, using truncateToSeconds on each to keep whole-second precision consistent with activeDeadlineSeconds and AICR_CHECK_TIMEOUT. enforcedDeadline's fallback returned an untruncated v1.JobDeadlineFor(...) while its doc comment claimed it matches what BuildJobPlan renders onto ActiveDeadlineSeconds, which truncates via int64(...Seconds()). Wrap the fallback in the same truncateToSeconds helper so the comment's claim is true. Adds an explicit sum assertion to TestValidatorTimeoutRelationships: the existing bounds-range and >= K8sPodReadyTimeout checks don't backstop a dropped ValidatorTerminationGracePeriod summand, since the resulting 2m still passes both. Signed-off-by: Alex Yuskauskas --- pkg/defaults/timeouts_test.go | 9 +++++++++ pkg/validator/job/result.go | 36 +++++++++++++++++++++++------------ 2 files changed, 33 insertions(+), 12 deletions(-) diff --git a/pkg/defaults/timeouts_test.go b/pkg/defaults/timeouts_test.go index 36d0859587..ebb3ee178b 100644 --- a/pkg/defaults/timeouts_test.go +++ b/pkg/defaults/timeouts_test.go @@ -273,6 +273,15 @@ func TestValidatorTimeoutRelationships(t *testing.T) { t.Errorf("ValidatorWaitBuffer (%v) must be at least K8sPodReadyTimeout (%v)", ValidatorWaitBuffer, K8sPodReadyTimeout) } + // The two checks above do not backstop a dropped summand: if + // ValidatorTerminationGracePeriod were dropped from ValidatorWaitBuffer's + // definition, the result (2m) would still pass both the bounds-range table + // test and the >= K8sPodReadyTimeout check above. Assert the sum of the two + // independently named constants directly so a dropped summand fails here. + if ValidatorWaitBuffer < K8sPodReadyTimeout+ValidatorTerminationGracePeriod { + t.Errorf("ValidatorWaitBuffer (%v) must be at least K8sPodReadyTimeout + ValidatorTerminationGracePeriod (%v)", + ValidatorWaitBuffer, K8sPodReadyTimeout+ValidatorTerminationGracePeriod) + } // Kubernetes must be the LOOSEST clock. If the Job deadline is not // strictly beyond the orchestrator's wait, the Job controller can kill and // delete the pod before the orchestrator reads its logs — issue #2473. diff --git a/pkg/validator/job/result.go b/pkg/validator/job/result.go index c305893155..fa399a7b28 100644 --- a/pkg/validator/job/result.go +++ b/pkg/validator/job/result.go @@ -359,28 +359,40 @@ func truncateToSeconds(d time.Duration) time.Duration { // enforced — so it is preferred whenever the Job could be read and carries it. // // The fallback derives the deadline v1.JobDeadlineFor(effectiveTimeout(configured)) -// would have produced — the same value BuildJobPlan renders onto -// ActiveDeadlineSeconds. It is unreachable in practice: the only caller, -// missingPodOutcome, sits behind an `if !ok { return -1, notFound }` guard -// that requires jobFailedCondition to have already succeeded, so job is -// non-nil here only when a live Job was just read with ActiveDeadlineSeconds -// set — both renderers in pkg/validator/v1/job_plan.go always set it. +// would have produced, truncated to whole seconds — the same value BuildJobPlan +// renders onto ActiveDeadlineSeconds via int64(JobDeadlineFor(timeout).Seconds()). +// It is unreachable in practice: the only caller, missingPodOutcome, sits behind +// an `if !ok { return -1, notFound }` guard that requires jobFailedCondition to +// have already succeeded, so job is non-nil here only when a live Job was just +// read with ActiveDeadlineSeconds set — both renderers in +// pkg/validator/v1/job_plan.go always set it. func enforcedDeadline(job *batchv1.Job, configured time.Duration) time.Duration { if job != nil && job.Spec.ActiveDeadlineSeconds != nil { return time.Duration(*job.Spec.ActiveDeadlineSeconds) * time.Second } - return v1.JobDeadlineFor(effectiveTimeout(configured)) + return truncateToSeconds(v1.JobDeadlineFor(effectiveTimeout(configured))) } // waitFailureMessage renders the TerminationMsg for a validator whose container // never terminated. Only a genuine context-deadline expiry is reported as a -// "timeout ... within " — any other cause (infra/unavailable) is -// surfaced verbatim so diagnosis is not misdirected to the catalog timeout -// (see issue #1966). A nil cause is treated as a timeout for backward -// compatibility with callers that had no error to thread through. +// timeout — any other cause (infra/unavailable) is surfaced verbatim so +// diagnosis is not misdirected to the catalog timeout (see issue #1966). A nil +// cause is treated as a timeout for backward compatibility with callers that +// had no error to thread through. +// +// The timeout wording names the actual clock the orchestrator waited on +// (WaitForCompletion's timeout+defaults.ValidatorWaitBuffer), not just the +// catalog budget: since #2473 the Job's own activeDeadlineSeconds exceeds the +// catalog budget by ValidatorJobDeadlineHeadroom, so a hung check now +// routinely expires this orchestrator wait before the Job deadline, and +// reporting only the catalog value would understate how long the operator +// actually waited. func waitFailureMessage(cause error, configured time.Duration) string { if cause == nil || isDeadlineCause(cause) { - return fmt.Sprintf("timeout: validator did not complete within %s", configured) + checkBudget := truncateToSeconds(configured) + waitBuffer := truncateToSeconds(defaults.ValidatorWaitBuffer) + return fmt.Sprintf("timeout: validator did not complete within %s (check budget %s + orchestrator wait buffer %s)", + checkBudget+waitBuffer, checkBudget, waitBuffer) } return fmt.Sprintf("validation failed: %v", cause) } From 0e7407a345fda1a6f77e1a5df3a299cc12c8d2fc Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Wed, 9 Sep 2026 11:16:27 -0700 Subject: [PATCH 13/22] docs(validator): correct stale Job-deadline headroom claims A few statements were missed by this branch's own sweep after adding ValidatorJobDeadlineHeadroom (3m30s): - docs/user/validation.md's "Benchmark Job stuck or timed out" section still described activeDeadlineSeconds as set by the catalog timeout alone. - docs/contributor/validator.md's RDMA eager-disclosure-floor section still asserted the "no-margin poll budget" SIGKILL premise that the matching Go comment in expected_resources.go was already updated to retract. - pkg/defaults/timeouts.go's CheckExecutionTimeout doc conflated the check budget with the Job deadline ("shorter than the catalog-level Job timeout (activeDeadlineSeconds)"); it should name AICR_CHECK_TIMEOUT, which is what it is actually compared against. - pkg/client/v1/aicr.go named "the largest per-check Job timeout (the 65m inference-perf catalog timeout)" without the headroom added on top; the pkg/defaults mirror of this sentence was already updated to 68m30s, this one was not. The conclusion (75m facade cap sits above it) was already correct -- only the number was stale. Also documents on JobPlan.CheckTimeout that it is informational only after BuildJobPlan returns (buildEnv already bakes the same value into plan.Env at build time), and on JobPlan.JobDeadline that leaving it at its zero value yields an instantly-exceeded Job. Comment-only; no defaulting logic added. Signed-off-by: Alex Yuskauskas --- docs/contributor/validator.md | 13 +++++++++---- docs/user/validation.md | 2 +- pkg/client/v1/aicr.go | 3 ++- pkg/defaults/timeouts.go | 4 +++- pkg/validator/v1/job_plan.go | 11 +++++++++-- 5 files changed, 24 insertions(+), 9 deletions(-) diff --git a/docs/contributor/validator.md b/docs/contributor/validator.md index 43ec20ac3c..8166ed6c17 100644 --- a/docs/contributor/validator.md +++ b/docs/contributor/validator.md @@ -655,10 +655,15 @@ enumerates any RDMA-candidate node (with `nodesValidated=0` — nothing is certified mid-poll) and again at the terminal outcome. `parseExtraSentinels` keeps the last valid sentinel, so the terminal emit wins on a clean exit; the floor exists only so a cordoned-node narrowing -still reaches the signed bundle if the Job's `activeDeadlineSeconds` -SIGKILLs the process at the no-margin poll budget before the terminal emit -runs (#1952). The gate stays fail-closed: "could not observe the fabric" -reports `0` validated and never reads as ready. +still reaches the signed bundle on the rarer path where the process is +SIGKILLed before the terminal emit runs (#1952). The broader no-margin kill +race this once described (#2473) is now bounded generally by +`ValidatorJobDeadlineHeadroom`: the Job's `activeDeadlineSeconds` adds that +headroom on top of the catalog `timeout:`, so an exhausted poll has margin to +unwind and reach the terminal emit before the Job's SIGKILL, and this floor +remains defense-in-depth for a probe call that blocks past its own +poll-budget cancellation. The gate stays fail-closed: "could not observe the +fabric" reports `0` validated and never reads as ready. Unlike `check-nvidia-smi`, the RDMA gate never *skips* — it either certifies the cohort or fails closed — so it mints no `skipReason` diff --git a/docs/user/validation.md b/docs/user/validation.md index 24c892d6e0..a52f993516 100644 --- a/docs/user/validation.md +++ b/docs/user/validation.md @@ -989,7 +989,7 @@ strategy. ### Benchmark Job stuck or timed out -Each performance check has a Job-level `activeDeadlineSeconds` set by the catalog's `timeout:`. For `inference-perf`, the full pipeline (workload ready → endpoint health → benchmark) can take up to 30 min on cold-start clusters. If it still times out: +Each performance check has a Job-level `activeDeadlineSeconds` set by the catalog's `timeout:` plus `ValidatorJobDeadlineHeadroom` (3m30s) on top. For `inference-perf`, the full pipeline (workload ready → endpoint health → benchmark) can take up to 30 min on cold-start clusters. If it still times out: ```bash # validator orchestrator Job + AIPerf benchmark Job both live in aicr-validation. diff --git a/pkg/client/v1/aicr.go b/pkg/client/v1/aicr.go index ca375bc65a..e0153865c5 100644 --- a/pkg/client/v1/aicr.go +++ b/pkg/client/v1/aicr.go @@ -2112,7 +2112,8 @@ func (c *Client) ValidateState( // Apply a facade-level deadline only as opted into by WithValidationTimeout, // mirroring MakeBundle. The default (cfg.timeout == nil) keeps the // ValidationOperationTimeout cap (75m), which sits ABOVE the largest - // per-check Job timeout (the 65m inference-perf catalog timeout; the + // rendered per-check Job deadline (the 65m inference-perf catalog timeout + // plus the 3m30s ValidatorJobDeadlineHeadroom, i.e. 68m30s; the // CheckExecutionTimeout fallback is 55m), so a single hung check fires its // own per-check timeout first and surfaces as a structured check failure // rather than a wrapping deadline-exceeded that loses the per-check signal — diff --git a/pkg/defaults/timeouts.go b/pkg/defaults/timeouts.go index 25655aafa8..9ff64e70c8 100644 --- a/pkg/defaults/timeouts.go +++ b/pkg/defaults/timeouts.go @@ -581,7 +581,9 @@ const ( const ( // CheckExecutionTimeout is the parent context timeout for checks running // inside a K8s Job. Must be long enough for the slowest behavioral check - // and shorter than the catalog-level Job timeout (activeDeadlineSeconds). + // and shorter than the catalog's own check timeout (AICR_CHECK_TIMEOUT) — + // not the Job's activeDeadlineSeconds, which adds + // ValidatorJobDeadlineHeadroom on top of that check timeout. // // The ceiling is set by the cold-start inference benchmark, which runs // the following phases serially under the parent ctx: diff --git a/pkg/validator/v1/job_plan.go b/pkg/validator/v1/job_plan.go index d281d6263a..75f53df28e 100644 --- a/pkg/validator/v1/job_plan.go +++ b/pkg/validator/v1/job_plan.go @@ -73,12 +73,19 @@ type JobPlan struct { Resources corev1.ResourceRequirements // CheckTimeout is the budget the check itself is given, published to the - // container as AICR_CHECK_TIMEOUT. + // container as AICR_CHECK_TIMEOUT. Informational only once BuildJobPlan has + // returned: buildEnv already baked the same timeout value into plan.Env at + // build time, so mutating this field afterwards does not change what the + // container receives. CheckTimeout int64 // JobDeadline is the Job's activeDeadlineSeconds. It exceeds CheckTimeout // by defaults.ValidatorJobDeadlineHeadroom so the check always terminates - // itself first and its pod survives for log extraction. + // itself first and its pod survives for log extraction. Unlike + // CheckTimeout, RenderPlan reads this field directly, so it is not purely + // informational — but leaving it at its zero value yields a Job whose + // activeDeadlineSeconds is 0, which the Job controller treats as already + // exceeded, killing the pod instantly. JobDeadline int64 // ServiceAccount is the Kubernetes ServiceAccount name From ed21b2e2095c1f9c9632a4b599f45eee09fa17cb Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Thu, 10 Sep 2026 13:07:28 -0700 Subject: [PATCH 14/22] fix(validator): anchor the Job-completion wait to the Job's start time Kubernetes measures activeDeadlineSeconds from the Job's status.startTime, but the orchestrator only began its own wait once the apply response landed. With a delay d between Job persistence and that response, AICR gave up at d + timeout + ValidatorWaitBuffer while Kubernetes fired at timeout + ValidatorJobDeadlineHeadroom, so Kubernetes won whenever d > JobEnvelopeMargin (60s) and deleted the still-active pod holding the verdict the headroom exists to preserve. DeployJob now records the Job's observed start time from the apply response (status.startTime, falling back to creationTimestamp) and WaitForCompletion derives its remaining wait from that origin via the new v1.OrchestratorWaitFor, capped at the un-rebased budget for apiserver clock skew and floored at defaults.ValidatorMinCompletionWait so a pathological delay cannot report a timeout before anything ran. Signed-off-by: Alex Yuskauskas --- docs/design/002-validatorv2-adr.md | 12 +++- docs/user/validation.md | 2 +- pkg/defaults/timeouts.go | 10 +++ pkg/defaults/timeouts_test.go | 14 ++++ pkg/validator/job/deployer.go | 38 ++++++++++- pkg/validator/job/deployer_test.go | 106 +++++++++++++++++++++++++++++ pkg/validator/job/result.go | 14 ++-- pkg/validator/v1/job_plan.go | 39 +++++++++++ pkg/validator/v1/job_plan_test.go | 106 +++++++++++++++++++++++++++++ 9 files changed, 330 insertions(+), 11 deletions(-) diff --git a/docs/design/002-validatorv2-adr.md b/docs/design/002-validatorv2-adr.md index cd7b1c1b7d..1cf3f254ef 100644 --- a/docs/design/002-validatorv2-adr.md +++ b/docs/design/002-validatorv2-adr.md @@ -155,6 +155,16 @@ check's own budget is always the tightest — the ordering that closes issue 2. **Orchestrator wait timeout** (catalog timeout + `defaults.ValidatorWaitBuffer`, 2m30s): if the Job hasn't reached a terminal state by then, the orchestrator captures whatever logs/status are available and moves to the next validator. + The window is measured from the Job's **observed start time** — `status.startTime` + when the apiserver has stamped it, otherwise `creationTimestamp` — not from the + moment the create/apply response reached the CLI, so it shares an origin with + clock 3 below. Anchored anywhere else, the real margin between clocks 2 and 3 + collapses to `defaults.JobEnvelopeMargin` (60s), because clock 3 has already + been running for however long the apply response took: a response slower than + that lets clock 3 fire first and delete the still-active pod. `v1.OrchestratorWaitFor` + carries the derivation; it caps the result at the un-rebased budget (apiserver + clock skew can place the start time in the CLI's future) and floors it at + `defaults.ValidatorMinCompletionWait`. 3. **Job `activeDeadlineSeconds`** (catalog timeout + `defaults.ValidatorJobDeadlineHeadroom`, 3m30s): K8s sends SIGTERM, then SIGKILL after `terminationGracePeriodSeconds` (30s), @@ -208,7 +218,7 @@ ValidateAll(ctx, recipe, snapshot) │ ├── For each validator (sequentially): │ │ ├── Deploy Job │ │ ├── Stream stderr (background, for live progress) -│ │ ├── WaitForCompletion(timeout + ValidatorWaitBuffer) +│ │ ├── WaitForCompletion() — until jobStart + timeout + ValidatorWaitBuffer │ │ ├── ExtractResult() — exit code, termination msg, stdout │ │ ├── Add to CTRF report │ │ └── CleanupJob() unless --no-cleanup diff --git a/docs/user/validation.md b/docs/user/validation.md index a52f993516..02c0604936 100644 --- a/docs/user/validation.md +++ b/docs/user/validation.md @@ -876,7 +876,7 @@ error codes (see [`pkg/errors/exitcode.go`](https://github.com/NVIDIA/aicr/blob/ > **Important:** two subtleties to be aware of when gating a pipeline on exit code: > -> 1. Both `failed` and `other` are blocking. A phase whose status is `other` — the check produced no usable verdict, e.g. a crash, an OOM, or a Job that failed for a non-deadline reason with its pod already gone — drives the same non-zero exit as `failed` — an inconclusive check fails closed rather than passing silently. `--fail-on-error=false` suppresses **both** result-driven exits (the run reports the outcomes in the CTRF report and exits 0); it does not distinguish `failed` from `other`. A validator Job killed on `activeDeadlineSeconds` normally reports `failed` rather than `other`: its terminal `Failed/DeadlineExceeded` condition is a verdict, so the result names the deadline instead of the missing pod. One narrow exception remains — the CLI waits the catalog timeout plus `ValidatorWaitBuffer` (2m30s) for the Job to become terminal, a window that is deliberately shorter than the Job's own `activeDeadlineSeconds` (catalog timeout plus `ValidatorJobDeadlineHeadroom`, 3m30s), so a validator whose pod is still running when the CLI's wait expires exhausts the wait before the deadline condition is ever stamped. Such a run falls back to the CLI-wait path and still reports `other`. +> 1. Both `failed` and `other` are blocking. A phase whose status is `other` — the check produced no usable verdict, e.g. a crash, an OOM, or a Job that failed for a non-deadline reason with its pod already gone — drives the same non-zero exit as `failed` — an inconclusive check fails closed rather than passing silently. `--fail-on-error=false` suppresses **both** result-driven exits (the run reports the outcomes in the CTRF report and exits 0); it does not distinguish `failed` from `other`. A validator Job killed on `activeDeadlineSeconds` normally reports `failed` rather than `other`: its terminal `Failed/DeadlineExceeded` condition is a verdict, so the result names the deadline instead of the missing pod. One narrow exception remains — the CLI waits the catalog timeout plus `ValidatorWaitBuffer` (2m30s) for the Job to become terminal — measured from the Job's own start time, so it shares an origin with the Job's clock — a window that is deliberately shorter than the Job's own `activeDeadlineSeconds` (catalog timeout plus `ValidatorJobDeadlineHeadroom`, 3m30s), so a validator whose pod is still running when the CLI's wait expires exhausts the wait before the deadline condition is ever stamped. Such a run falls back to the CLI-wait path and still reports `other`. > 2. Exit 5 is narrower than it sounds. A timeout **inside** a check's own logic (DynamoGraphDeployment not ready, inference endpoint never healthy, AIPerf Job pod-wait deadline) surfaces as a failed phase, not as a structured `ErrCodeTimeout`, so the CLI exits **8**. So does a per-validator wait deadline: `runPhase` hands that error to the timeout handler and records the outcome as a check result rather than propagating it, which is the same path the wait-exhaustion exception in note 1 takes. The rule, rather than a list of sources: exit 5 applies whenever an `ErrCodeTimeout` reaches the top-level CLI. A timeout that is converted into a check result instead — whether raised inside a check or by a per-validator wait — surfaces as exit 8. Scripts that gate on validation outcome should treat **any non-zero code** as diff --git a/pkg/defaults/timeouts.go b/pkg/defaults/timeouts.go index 9ff64e70c8..5c5e47b8a6 100644 --- a/pkg/defaults/timeouts.go +++ b/pkg/defaults/timeouts.go @@ -1158,6 +1158,16 @@ const ( // instead of the Job controller deleting it as an active pod (issue #2473). ValidatorJobDeadlineHeadroom = ValidatorWaitBuffer + JobEnvelopeMargin + // ValidatorMinCompletionWait floors the orchestrator's Job-completion wait + // once that wait has been rebased onto the Job's observed start time. The + // rebase subtracts however long the create/apply response took to arrive, + // and a pathological delay would otherwise leave a zero or negative + // remainder — an orchestrator timeout reported before the check ran. One + // SIGTERM-to-SIGKILL window is the shortest span in which a Job already + // past its activeDeadlineSeconds can still stamp a terminal condition for + // the orchestrator to read. + ValidatorMinCompletionWait = ValidatorTerminationGracePeriod + // ValidatorDefaultTimeout is the default per-validator timeout if not // specified in the catalog. Used as fallback only. ValidatorDefaultTimeout = 5 * time.Minute diff --git a/pkg/defaults/timeouts_test.go b/pkg/defaults/timeouts_test.go index ebb3ee178b..8fc1cbd919 100644 --- a/pkg/defaults/timeouts_test.go +++ b/pkg/defaults/timeouts_test.go @@ -74,6 +74,7 @@ func TestTimeoutConstants(t *testing.T) { {"ValidatorJobDeadlineHeadroom", ValidatorJobDeadlineHeadroom, 1 * time.Minute, 10 * time.Minute}, {"ValidatorDefaultTimeout", ValidatorDefaultTimeout, 1 * time.Minute, 15 * time.Minute}, {"ValidatorTerminationGracePeriod", ValidatorTerminationGracePeriod, 10 * time.Second, 60 * time.Second}, + {"ValidatorMinCompletionWait", ValidatorMinCompletionWait, 10 * time.Second, 60 * time.Second}, // ConfigMap read/write budgets — held as distinct constants so the // read path (serializer resolving cm:// URIs) and the write path @@ -289,6 +290,19 @@ func TestValidatorTimeoutRelationships(t *testing.T) { t.Errorf("ValidatorJobDeadlineHeadroom (%v) must exceed ValidatorWaitBuffer (%v)", ValidatorJobDeadlineHeadroom, ValidatorWaitBuffer) } + // The floor on a start-time-rebased wait has to leave room for a Job past + // its deadline to stamp a terminal condition, which takes at least the + // pod's SIGTERM-to-SIGKILL window; and it must stay under the wait buffer, + // or a floor larger than the budget it clamps would extend every wait + // instead of bounding the clamped ones. + if ValidatorMinCompletionWait < ValidatorTerminationGracePeriod { + t.Errorf("ValidatorMinCompletionWait (%v) must be at least ValidatorTerminationGracePeriod (%v)", + ValidatorMinCompletionWait, ValidatorTerminationGracePeriod) + } + if ValidatorMinCompletionWait > ValidatorWaitBuffer { + t.Errorf("ValidatorMinCompletionWait (%v) must not exceed ValidatorWaitBuffer (%v)", + ValidatorMinCompletionWait, ValidatorWaitBuffer) + } // Default timeout must be positive and reasonable. if ValidatorDefaultTimeout < 1*time.Minute { t.Errorf("ValidatorDefaultTimeout (%v) should be at least 1m", ValidatorDefaultTimeout) diff --git a/pkg/validator/job/deployer.go b/pkg/validator/job/deployer.go index d9aee89fbf..a62e612553 100644 --- a/pkg/validator/job/deployer.go +++ b/pkg/validator/job/deployer.go @@ -29,6 +29,7 @@ import ( "github.com/NVIDIA/aicr/pkg/validator/catalog" "github.com/NVIDIA/aicr/pkg/validator/labels" v1 "github.com/NVIDIA/aicr/pkg/validator/v1" + batchv1 "k8s.io/api/batch/v1" corev1 "k8s.io/api/core/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/client-go/informers" @@ -77,6 +78,11 @@ type Config struct { type Deployer struct { config Config jobName string // Unique name generated client-side (set by DeployJob) + // jobStart is the apiserver-side moment Kubernetes began measuring the + // Job's activeDeadlineSeconds, read off the apply response by DeployJob. + // WaitForCompletion anchors its own deadline to it so both clocks share an + // origin; zero until DeployJob succeeds. + jobStart time.Time } // NewDeployer creates a Deployer for a single validator catalog entry. @@ -147,15 +153,37 @@ func (d *Deployer) DeployJob(ctx context.Context) error { } d.jobName = applied.Name + d.jobStart = observedJobStart(applied) slog.Debug("validator Job applied", "job", d.jobName, "validator", d.config.Entry.Name, - "namespace", d.config.Namespace) + "namespace", d.config.Namespace, + "jobStart", d.jobStart) return nil } +// observedJobStart returns the apiserver-side moment Kubernetes started +// measuring the Job's activeDeadlineSeconds. +// +// status.startTime is the field the Job controller measures against, but it +// stamps it on its first reconcile, so it is normally still absent from the +// response to the create/apply that produced the Job. creationTimestamp is the +// fallback: it is never later than status.startTime, which keeps any deadline +// derived from it on the earlier-expiring side. A nil Job, or one the apiserver +// returned without either timestamp, yields the zero time — see +// v1.OrchestratorWaitFor for how callers treat that. +func observedJobStart(job *batchv1.Job) time.Time { + if job == nil { + return time.Time{} + } + if job.Status.StartTime != nil { + return job.Status.StartTime.Time + } + return job.CreationTimestamp.Time +} + // Stable reason codes for affinityScanWarning, suitable for log filtering // and metric labels. Kept short and ASCII so they round-trip through any // downstream sink without escaping. @@ -313,8 +341,14 @@ func (d *Deployer) CleanupJob(ctx context.Context) error { // in the validator orchestrator, not in the shared pod.WaitForJobTerminal // helper, which intentionally treats both Complete and Failed Jobs as // legitimate completions and lets the caller classify them. +// +// The wait is anchored to the Job's observed start time rather than to the +// moment this method was called, so it and the Job's own activeDeadlineSeconds +// are measured from the same origin and the orchestrator stays the tighter +// clock however long the apply response took to arrive. v1.OrchestratorWaitFor +// carries the derivation. func (d *Deployer) WaitForCompletion(ctx context.Context, timeout time.Duration) error { - waitTimeout := timeout + defaults.ValidatorWaitBuffer + waitTimeout := v1.OrchestratorWaitFor(d.jobStart, time.Now(), timeout) // pod.WaitForJobTerminal already returns structured errors with proper // codes (ErrCodeTimeout, ErrCodeUnavailable, ErrCodeInternal). Propagate // as-is so callers can distinguish retryable from terminal failures. diff --git a/pkg/validator/job/deployer_test.go b/pkg/validator/job/deployer_test.go index 60edd2d37d..1112ed395b 100644 --- a/pkg/validator/job/deployer_test.go +++ b/pkg/validator/job/deployer_test.go @@ -1073,3 +1073,109 @@ func TestScanMissingPodAffinityDeps_StopsOnCancellation(t *testing.T) { t.Errorf("expected no warnings after pre-canceled ctx, got %d: %v", len(got), got) } } + +// TestDeployJobAnchorsWaitToObservedJobStart is the deployer half of the +// clock-origin regression for issue #2473. The Job's activeDeadlineSeconds is +// measured by Kubernetes from the Job's start time, so the orchestrator's own +// wait has to be measured from there too — not from the moment the apply +// response happened to land. The reactor returns a Job whose creationTimestamp +// is already 90s old, standing in for an apply response delayed past +// defaults.JobEnvelopeMargin, which is exactly the case where an unrebased wait +// outlived the Job deadline and let the Job controller delete the pod holding +// the verdict. +// +// No wall-clock sleeping: the delay is expressed entirely in the timestamp the +// fake apiserver reports. +func TestDeployJobAnchorsWaitToObservedJobStart(t *testing.T) { + t.Parallel() + + const applyDelay = 90 * time.Second // 30s past defaults.JobEnvelopeMargin + entry := testEntry() + created := metav1.NewTime(time.Now().Add(-applyDelay).Truncate(time.Second)) + + //nolint:staticcheck // SA1019: fake.NewSimpleClientset is sufficient for tests + cs := fake.NewSimpleClientset() + cs.PrependReactor("patch", "jobs", func(action clienttesting.Action) (bool, runtime.Object, error) { + return true, &batchv1.Job{ + ObjectMeta: metav1.ObjectMeta{ + Name: "aicr-gpu-operator-health-abcdef", + Namespace: "aicr-validation", + CreationTimestamp: created, + }, + }, nil + }) + + d := NewDeployer(Config{ + Clientset: cs, + Factory: informers.NewSharedInformerFactory(cs, 0), + Namespace: "aicr-validation", + RunID: "run-1", + Entry: entry, + }) + if err := d.DeployJob(context.Background()); err != nil { + t.Fatalf("DeployJob() failed: %v", err) + } + + if !d.jobStart.Equal(created.Time) { + t.Fatalf("jobStart = %v, want the apply response's creationTimestamp %v", d.jobStart, created.Time) + } + + // The wait WaitForCompletion would derive from that origin. Entry timeout + // is 2m, so the unrebased budget is 2m+2m30s = 4m30s and the Job deadline + // is 2m+3m30s = 5m30s. Rebased onto a 90s-old start the wait is ~3m, and + // the whole wait fits inside the Job deadline measured from the same + // origin; unrebased it would have ended 90s past that deadline. + now := time.Now() + wait := v1.OrchestratorWaitFor(d.jobStart, now, entry.Timeout) + budget := entry.Timeout + defaults.ValidatorWaitBuffer + if wait >= budget { + t.Errorf("derived wait = %v, want less than the unrebased budget %v", wait, budget) + } + if end, deadline := now.Add(wait), d.jobStart.Add(v1.JobDeadlineFor(entry.Timeout)); !end.Before(deadline) { + t.Errorf("orchestrator wait ends at %v, want strictly before the Job deadline at %v", end, deadline) + } +} + +// TestObservedJobStartPrefersStatusStartTime pins the fallback order: +// status.startTime is what the Job controller measures activeDeadlineSeconds +// against, and creationTimestamp stands in only until the controller stamps it. +func TestObservedJobStartPrefersStatusStartTime(t *testing.T) { + t.Parallel() + + created := metav1.NewTime(time.Now().Add(-2 * time.Minute).Truncate(time.Second)) + started := metav1.NewTime(created.Add(15 * time.Second)) + + tests := []struct { + name string + job *batchv1.Job + want time.Time + }{ + { + name: "nil Job yields the zero time", + job: nil, + want: time.Time{}, + }, + { + name: "creationTimestamp is the fallback before the controller reconciles", + job: &batchv1.Job{ObjectMeta: metav1.ObjectMeta{CreationTimestamp: created}}, + want: created.Time, + }, + { + name: "status.startTime wins once set", + job: &batchv1.Job{ + ObjectMeta: metav1.ObjectMeta{CreationTimestamp: created}, + Status: batchv1.JobStatus{StartTime: &started}, + }, + want: started.Time, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + if got := observedJobStart(tt.job); !got.Equal(tt.want) { + t.Errorf("observedJobStart() = %v, want %v", got, tt.want) + } + }) + } +} diff --git a/pkg/validator/job/result.go b/pkg/validator/job/result.go index fa399a7b28..f0d6be686b 100644 --- a/pkg/validator/job/result.go +++ b/pkg/validator/job/result.go @@ -380,13 +380,13 @@ func enforcedDeadline(job *batchv1.Job, configured time.Duration) time.Duration // cause is treated as a timeout for backward compatibility with callers that // had no error to thread through. // -// The timeout wording names the actual clock the orchestrator waited on -// (WaitForCompletion's timeout+defaults.ValidatorWaitBuffer), not just the -// catalog budget: since #2473 the Job's own activeDeadlineSeconds exceeds the -// catalog budget by ValidatorJobDeadlineHeadroom, so a hung check now -// routinely expires this orchestrator wait before the Job deadline, and -// reporting only the catalog value would understate how long the operator -// actually waited. +// The timeout wording names the actual clock the orchestrator waited on — +// configured+defaults.ValidatorWaitBuffer, the window WaitForCompletion spans +// measured from the Job's start time — not just the catalog budget: since +// #2473 the Job's own activeDeadlineSeconds exceeds the catalog budget by +// ValidatorJobDeadlineHeadroom, so a hung check now routinely expires this +// orchestrator wait before the Job deadline, and reporting only the catalog +// value would understate how long the operator actually waited. func waitFailureMessage(cause error, configured time.Duration) string { if cause == nil || isDeadlineCause(cause) { checkBudget := truncateToSeconds(configured) diff --git a/pkg/validator/v1/job_plan.go b/pkg/validator/v1/job_plan.go index 75f53df28e..0ecbb00a69 100644 --- a/pkg/validator/v1/job_plan.go +++ b/pkg/validator/v1/job_plan.go @@ -201,6 +201,45 @@ func JobDeadlineFor(checkTimeout time.Duration) time.Duration { return checkTimeout + defaults.ValidatorJobDeadlineHeadroom } +// OrchestratorWaitFor returns how much longer a caller should wait for a +// validator Job to reach a terminal state, given the Job's observed start time +// (see the observedStart contract below) and the check's own budget. +// +// The two clocks do not share an origin. Kubernetes measures +// activeDeadlineSeconds from the Job's status.startTime, whereas a caller can +// only begin waiting once the create/apply response reaches it. Anchoring the +// wait to observedStart instead of to now removes that delay from the +// comparison, so a caller that waits checkTimeout+defaults.ValidatorWaitBuffer +// still expires before the Job's checkTimeout+defaults.ValidatorJobDeadlineHeadroom +// no matter how slow the response was. Without the rebase the effective margin +// between the two is only defaults.JobEnvelopeMargin, and a response slower +// than that lets the Job controller win and delete the still-active pod whose +// logs carry the verdict (issue #2473). +// +// observedStart is status.startTime when the caller has seen it, else the Job's +// creationTimestamp — never later than status.startTime, so the fallback ends +// the wait earlier rather than later. A zero observedStart means no start time +// was observed at all and yields the unrebased budget. +// +// The result is capped at that same unrebased budget, because apiserver clock +// skew can place observedStart in the caller's future, and floored at +// defaults.ValidatorMinCompletionWait so a pathological response delay does not +// produce a wait too short to observe a terminal condition. +func OrchestratorWaitFor(observedStart, now time.Time, checkTimeout time.Duration) time.Duration { + budget := checkTimeout + defaults.ValidatorWaitBuffer + if observedStart.IsZero() { + return budget + } + remaining := observedStart.Add(budget).Sub(now) + if remaining > budget { + return budget + } + if remaining < defaults.ValidatorMinCompletionWait { + return defaults.ValidatorMinCompletionWait + } + return remaining +} + // BuildJobPlan creates a JobPlan from a validator entry. // Exposed as public for verification and testing purposes. // diff --git a/pkg/validator/v1/job_plan_test.go b/pkg/validator/v1/job_plan_test.go index 9110553d31..b55d4b5bb5 100644 --- a/pkg/validator/v1/job_plan_test.go +++ b/pkg/validator/v1/job_plan_test.go @@ -21,6 +21,7 @@ import ( "testing" "time" + "github.com/NVIDIA/aicr/pkg/defaults" "github.com/NVIDIA/aicr/pkg/errors" "github.com/NVIDIA/aicr/pkg/recipe" corev1 "k8s.io/api/core/v1" @@ -1363,3 +1364,108 @@ func TestBuildResources_NilOrEmptyUsesDefaults(t *testing.T) { }) } } + +// TestOrchestratorWaitForRebasesOntoJobStart is the regression test for the +// clock-origin half of issue #2473. Kubernetes measures activeDeadlineSeconds +// from the Job's start time, but the orchestrator can only start waiting once +// the create/apply response reaches it. Anchoring the wait to the observed +// start time is what keeps the orchestrator the tighter clock when that +// response is slow; without it the effective margin between the two deadlines +// is only defaults.JobEnvelopeMargin, and a slower response lets the Job +// controller fire first and delete the still-active pod holding the verdict. +// +// Each case asserts the property that matters — observedStart + wait must land +// strictly before observedStart + JobDeadlineFor(checkTimeout), i.e. the whole +// orchestrator wait fits inside the Job's own deadline measured from the same +// origin. +func TestOrchestratorWaitForRebasesOntoJobStart(t *testing.T) { + t.Parallel() + + const checkTimeout = 5 * time.Minute + budget := checkTimeout + defaults.ValidatorWaitBuffer // 5m + 2m30s = 7m30s + jobDeadline := JobDeadlineFor(checkTimeout) // 5m + 3m30s = 8m30s + start := time.Date(2026, 9, 8, 12, 0, 0, 0, time.UTC) + + tests := []struct { + name string + applyDelay time.Duration // how long the apply response took to arrive + want time.Duration + // floored marks the case where the remainder was clamped to + // defaults.ValidatorMinCompletionWait. The Job deadline is already in + // the past by then, so the fit-inside-the-deadline invariant below + // cannot hold and is not asserted; the floor's job is only to leave + // enough wall clock to read the terminal condition Kubernetes stamped. + floored bool + }{ + { + name: "instant apply response leaves the full budget", + applyDelay: 0, + want: budget, + }, + { + name: "delay inside JobEnvelopeMargin still shortens the wait", + applyDelay: 30 * time.Second, + want: budget - 30*time.Second, // 7m + }, + { + // The pre-fix failure mode: a 90s apply response is 30s past + // JobEnvelopeMargin, so an unrebased wait would have ended at + // 90s+7m30s = 9m after job start — 30s AFTER the 8m30s Job + // deadline. Rebased, it ends at 7m30s after job start, 1m early. + name: "delay beyond JobEnvelopeMargin no longer outlives the Job deadline", + applyDelay: 90 * time.Second, + want: budget - 90*time.Second, // 6m + }, + { + name: "pathological delay is floored, not driven negative", + applyDelay: budget + time.Hour, + want: defaults.ValidatorMinCompletionWait, // 30s + floored: true, + }, + { + // Apiserver clock skew can place the observed start in the + // caller's future; the wait must not exceed the nominal budget. + name: "start time in the caller's future is capped at the budget", + applyDelay: -time.Hour, + want: budget, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + now := start.Add(tt.applyDelay) + got := OrchestratorWaitFor(start, now, checkTimeout) + if got != tt.want { + t.Errorf("OrchestratorWaitFor(start, start+%v, %v) = %v, want %v", + tt.applyDelay, checkTimeout, got, tt.want) + } + if tt.floored { + return + } + // The invariant the fix exists to hold: the orchestrator's wait, + // measured from the same origin Kubernetes uses, ends before the + // Job's activeDeadlineSeconds does. + orchestratorEnd := now.Add(got) + jobEnd := start.Add(jobDeadline) + if !orchestratorEnd.Before(jobEnd) { + t.Errorf("orchestrator wait ends at %v, want strictly before the Job deadline at %v", + orchestratorEnd, jobEnd) + } + }) + } +} + +// TestOrchestratorWaitForUnobservedStart pins the zero-time contract: a caller +// that never saw a start time gets the unrebased budget, which is the +// pre-#2473 behavior and still strictly under the Job deadline as long as the +// apply response itself was not the thing that was slow. +func TestOrchestratorWaitForUnobservedStart(t *testing.T) { + t.Parallel() + + const checkTimeout = 5 * time.Minute + want := checkTimeout + defaults.ValidatorWaitBuffer + if got := OrchestratorWaitFor(time.Time{}, time.Now(), checkTimeout); got != want { + t.Errorf("OrchestratorWaitFor(zero, now, %v) = %v, want %v", checkTimeout, got, want) + } +} From 4d3246a560d17027468f1a292ed9ad31122d8ab0 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Thu, 10 Sep 2026 13:07:39 -0700 Subject: [PATCH 15/22] fix(validator): report every check an exhausted budget left unevaluated MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit markUndispatched only named the chainsaw asserts already queued when the enabledRefs loop broke, so a budget that expired partway through dropped every later component's health check from the report — an operator read a short failure list and concluded the rest of the cluster was fine. It now also names the components the iteration never reached and the GPU readiness probes that were skipped. Those GPU probes are now skipped rather than run once the budget is gone. Their poll loops observe ctx.Ctx, but expectedNodewrightNames takes no context at all, so its value resolution and manifest rendering ran to completion on an already-dead budget and delayed the failure report without producing a verdict. The fan-out is extracted as runGPUReadinessProbes so its concurrency can be proven directly: a rendezvous that releases nobody until every probe has arrived, which a serial implementation cannot satisfy. The equivalent barrier at the client level is not possible here — testing.Fake.Invokes holds one mutex across the whole reaction chain, so blocking in a reactor starves the sibling probe and self-deadlocks either way. Signed-off-by: Alex Yuskauskas --- validators/deployment/expected_resources.go | 253 ++++++++++++------ .../deployment/expected_resources_test.go | 253 +++++++++++++++++- 2 files changed, 420 insertions(+), 86 deletions(-) diff --git a/validators/deployment/expected_resources.go b/validators/deployment/expected_resources.go index f181c596d0..853eab86d7 100644 --- a/validators/deployment/expected_resources.go +++ b/validators/deployment/expected_resources.go @@ -199,15 +199,25 @@ func pollUntilStable(ctx *validators.Context, label string, probe func() error, // // The two ctx.Done() checks (expected-resources iteration, GPU readiness / // chainsaw dispatch) never return early: they record the stage in -// budgetExhausted, mark undispatched work, print the accumulated failures, -// and fail closed (issue #2473). "Mark undispatched work" covers only the -// chainsaw asserts already queued when the loop broke (via markUndispatched); -// enabledRefs entries the loop never reached produce no line at all. The -// second check is unconditional — it does not require any chainsaw asserts -// to have been queued, since verifyGPUReadinessSignals alone can exhaust the -// budget on a recipe that queued none. gatedHealthCheckSuppressed and -// buildResourceFetcher still return directly on error — both are hard -// errors, not budget-exhaustion handling. +// budgetExhausted, mark every piece of unevaluated work, print the accumulated +// failures, and fail closed (issue #2473). Unevaluated work is reported in +// three parts, all via markUndispatched: chainsaw asserts already queued when +// the loop broke, the health checks carried by enabledRefs entries the loop +// never reached, and the GPU readiness probes the enabled component set +// selects. Anything less understates how much of the cluster went unchecked. +// +// Once budgetExhausted is set the GPU probes are skipped rather than run. +// Their poll loops observe ctx.Ctx, but the work ahead of the first poll is not +// uniformly cancellation-bound — expectedNodewrightNames takes no context at +// all, so its value resolution and manifest rendering run to completion on an +// already-dead budget. Running the probes would delay the accumulated failure +// report without producing a verdict. The second ctx.Done() check therefore +// only runs on the path where the probes did execute, which is the path where +// they can still exhaust the budget themselves on a recipe whose enabled refs +// queued no asserts. +// +// gatedHealthCheckSuppressed and buildResourceFetcher still return directly on +// error — both are hard errors, not budget-exhaustion handling. // gatedHealthCheckSuppressed's error can itself be cancellation-induced (it // threads ctx.Ctx into a Helm render), and that path discards whatever // failures were already collected under an ErrCodeInternal wrap rather than @@ -239,6 +249,12 @@ func checkExpectedResources(ctx *validators.Context) error { // reporting block below is what made issue #2473 undiagnosable. var budgetExhausted string + // unreachedRefs are the enabledRefs the loop below never examined because + // the budget went first. Their health checks were never queued, so + // markUndispatched has to name them separately from chainsawAsserts or they + // vanish from the report entirely. + var unreachedRefs []recipe.ComponentRef + failures = append(failures, verifyNamespacesActive(ctx, enabledRefs)...) // When both ExpectedResources and HealthCheckAsserts are populated on @@ -252,7 +268,7 @@ func checkExpectedResources(ctx *validators.Context) error { // readiness signal and should always run alongside the overlay- // declared resource list. The transitional hydration skip in // pkg/recipe (added in #1234) was reverted in lockstep. - for _, ref := range enabledRefs { + for i, ref := range enabledRefs { // Honor cancellation between components so a canceled run stops // before issuing more API calls — per repo CLAUDE.md "Always // check ctx.Done() in long-running operations and loops". @@ -262,6 +278,9 @@ func checkExpectedResources(ctx *validators.Context) error { default: } if budgetExhausted != "" { + // This ref included: the guard trips before any of its own + // checks run, so it is unevaluated like the ones behind it. + unreachedRefs = enabledRefs[i:] break } if ref.HealthCheckAsserts != "" { @@ -295,28 +314,38 @@ func checkExpectedResources(ctx *validators.Context) error { } } - gpuFailures, gpuStructuredErr := verifyGPUReadinessSignals(ctx, enabledRefs) - failures = append(failures, gpuFailures...) - // firstStructuredErr is guaranteed nil here (the chainsaw block - // below is the only other producer and hasn't run yet); we can - // assign unconditionally. The chainsaw block downstream checks - // firstStructuredErr == nil before its own assignment so the GPU - // error wins when both produce one. - if gpuStructuredErr != nil { - firstStructuredErr = gpuStructuredErr - } + // gpuProbes is built even on the exhausted path: selection is offline (see + // enabledGPUReadinessProbes), and the labels are what let the report name + // the probes that were skipped. + gpuProbes := enabledGPUReadinessProbes(ctx, enabledRefs) + if budgetExhausted == "" { + gpuFailures, gpuStructuredErr := verifyGPUReadinessSignals(ctx, enabledRefs) + failures = append(failures, gpuFailures...) + // firstStructuredErr is guaranteed nil here (the chainsaw block + // below is the only other producer and hasn't run yet); we can + // assign unconditionally. The chainsaw block downstream checks + // firstStructuredErr == nil before its own assignment so the GPU + // error wins when both produce one. + if gpuStructuredErr != nil { + firstStructuredErr = gpuStructuredErr + } - // This probe must run regardless of whether any asserts were queued: - // verifyGPUReadinessSignals above can itself consume the remaining budget - // on a recipe whose enabled refs queued no chainsaw asserts, and skipping - // the check in that case is exactly the fail-open issue #2473 closed - // elsewhere in this function — an exhausted context with zero collected - // failures must still fail closed, not fall through to the healthy return. - if budgetExhausted == "" && ctx.Ctx.Err() != nil { - budgetExhausted = "GPU readiness / chainsaw dispatch" + // Re-checked after the probes rather than only before them: + // verifyGPUReadinessSignals can itself consume the remaining budget on + // a recipe whose enabled refs queued no chainsaw asserts, and letting + // that fall through to the healthy return is exactly the fail-open + // issue #2473 closed elsewhere in this function — an exhausted context + // with zero collected failures must still fail closed. + if ctx.Ctx.Err() != nil { + budgetExhausted = "GPU readiness / chainsaw dispatch" + // The probes above already ran, so only the queued asserts are + // still unevaluated; gpuProbes is deliberately not passed here. + gpuProbes = nil + } } + if budgetExhausted != "" { - failures = markUndispatched(failures, chainsawAsserts, budgetExhausted) + failures = markUndispatched(failures, chainsawAsserts, unreachedRefs, gpuProbes, budgetExhausted) } else if len(chainsawAsserts) > 0 { slog.Info("running health check assertions", "components", len(chainsawAsserts)) fetcher, fetcherErr := buildResourceFetcher(ctx) @@ -394,16 +423,43 @@ func enabledComponentRefs(refs []recipe.ComponentRef) []recipe.ComponentRef { return enabled } -// markUndispatched appends a not-evaluated line for every assert that was -// queued but never handed to chainsaw. Reporting them explicitly is what stops -// a truncated run from reading as a mostly-healthy cluster: the operator sees -// which components carry no verdict rather than inferring their absence means -// "fine". -func markUndispatched(failures []string, asserts []chainsaw.ComponentAssert, stage string) []string { +// markUndispatched appends a not-evaluated line for every piece of work the +// exhausted run left undone: each assert queued but never handed to chainsaw, +// each health check on a component the iteration never reached, and each GPU +// readiness probe skipped rather than run. Reporting them explicitly is what +// stops a truncated run from reading as a mostly-healthy cluster: the operator +// sees which components carry no verdict rather than inferring their absence +// means "fine". +// +// unreached and asserts are disjoint — a ref only reaches asserts by being +// examined, which is what unreached excludes — so no component is named twice. +// unreached refs are not filtered through gatedHealthCheckSuppressed: that +// render never ran for them, so whether their assert would have been suppressed +// is unknown, and reporting "not evaluated" is the fail-closed reading. +func markUndispatched( + failures []string, + asserts []chainsaw.ComponentAssert, + unreached []recipe.ComponentRef, + gpuProbes []gpuReadinessProbe, + stage string, +) []string { + for _, a := range asserts { failures = append(failures, fmt.Sprintf( "[chainsaw] %s: not evaluated — budget exhausted during %s", a.Name, stage)) } + for _, ref := range unreached { + if ref.HealthCheckAsserts == "" { + continue + } + failures = append(failures, fmt.Sprintf( + "[chainsaw] %s: not evaluated — budget exhausted during %s", ref.Name, stage)) + } + for _, p := range gpuProbes { + failures = append(failures, fmt.Sprintf( + "[gpuReadiness] %s (%s): not evaluated — budget exhausted during %s", + p.component, p.signal, stage)) + } return failures } @@ -475,10 +531,65 @@ func verifyGPUReadinessSignals(ctx *validators.Context, refs []recipe.ComponentR } } - // Build the probe list in a FIXED order. capture() below is applied to the - // results in that same order after the fan-out joins, so firstStructured - // precedence is identical to the previous serial implementation. - var probes []func() error + for _, err := range runGPUReadinessProbes(enabledGPUReadinessProbes(ctx, refs)) { + capture(err) + } + + return failures, firstStructured +} + +// runGPUReadinessProbes runs every probe concurrently and returns their results +// indexed by probes, so callers read them back in that fixed order rather than +// in completion order — which is what makes firstStructured precedence in +// verifyGPUReadinessSignals independent of which probe happens to finish first. +// +// Plain Group, not WithContext: every probe closes over a *validators.Context +// and reads ctx.Ctx directly (pollUntilStable), so a derived gctx would be +// built and discarded — the same reasoning as the Skyhook-status/taint-scan +// errgroup fan-out inside verifyNodewrightReady's own poll probe elsewhere in +// this file. Each goroutine writes its result into its own slice index and +// always returns nil, so one unhealthy signal never stops the others from +// running. +func runGPUReadinessProbes(probes []gpuReadinessProbe) []error { + results := make([]error, len(probes)) + g := new(errgroup.Group) + for i, probe := range probes { + g.Go(func() error { + results[i] = probe.run() + return nil + }) + } + // Goroutines never return an error (results are recorded per-index), so Wait + // only blocks until every probe completes. + _ = g.Wait() + return results +} + +// gpuReadinessProbe pairs a readiness probe with the component and signal it +// gates. The labels exist so the budget-exhausted path can report which probes +// went unevaluated without running any of them. +type gpuReadinessProbe struct { + // component is the recipe component whose enablement selected this probe. + component string + // signal names what the probe waits on, since one component can gate a + // signal narrower than itself (network-operator gates only the RDMA fabric). + signal string + // run is a single blocking pass of the probe; it observes ctx.Ctx through + // pollUntilStable and returns nil when the signal is healthy and settled. + run func() error +} + +// enabledGPUReadinessProbes returns the GPU readiness probes the enabled +// component set selects, in the FIXED order verifyGPUReadinessSignals reads +// results back in — that order is what firstStructured precedence depends on. +// +// Selection is offline: it branches on component names and the recipe's +// declared manifest file list, and the one client it touches (getDynamicClient, +// below) it only constructs. No probe body runs and no request is issued, which +// is what lets checkExpectedResources enumerate the probes it is skipping once +// the check budget is gone. +func enabledGPUReadinessProbes(ctx *validators.Context, refs []recipe.ComponentRef) []gpuReadinessProbe { + var probes []gpuReadinessProbe if ref, ok := findEnabledComponent(refs, nodewrightCustomizationsComponent); ok { // Warm ctx.DynamicClient before the fan-out: getDynamicClient writes it @@ -489,53 +600,41 @@ func verifyGPUReadinessSignals(ctx *validators.Context, refs []recipe.ComponentR // probe calls getDynamicClient again and surfaces the identical error, // and that call returns before the write, so no race is introduced. _, _ = getDynamicClient(ctx) - probes = append(probes, func() error { return verifyNodewrightReady(ctx, ref) }) + probes = append(probes, gpuReadinessProbe{ + component: nodewrightCustomizationsComponent, + signal: "Nodewright CR completion + runtime-required taint clearance", + run: func() error { return verifyNodewrightReady(ctx, ref) }, + }) } if ref, ok := findEnabledComponent(refs, draDriverComponent); ok { - probes = append(probes, func() error { return verifyDRAKubeletPluginReady(ctx, ref.Namespace) }) - } - - if ref, ok := findEnabledComponent(refs, networkOperatorComponent); ok && recipeDeclaresRDMAFabric(ref) { - probes = append(probes, func() error { - // The polled resource is derived from the recipe's own - // NicClusterPolicy manifest (rdma/hca_shared_devices_a on AKS, - // nvidia.com/mlnxnics on OKE) so the gate waits for exactly what - // this recipe's fabric advertises. A derivation failure fails the - // gate closed — never "skip the fabric". - fabricResource, ferr := rdmaFabricResource(ctx.Ctx, ref) - if ferr != nil { - return ferr - } - return verifyRDMAFabricReady(ctx, fabricResource) + probes = append(probes, gpuReadinessProbe{ + component: draDriverComponent, + signal: "DRA kubelet plugin readiness", + run: func() error { return verifyDRAKubeletPluginReady(ctx, ref.Namespace) }, }) } - // Plain Group, not WithContext: every probe takes *validators.Context and - // reads ctx.Ctx directly (pollUntilStable), so a derived gctx would be built - // and discarded — the same reasoning as the Skyhook-status/taint-scan - // errgroup fan-out inside verifyNodewrightReady's own poll probe elsewhere - // in this file. Each goroutine writes its result into its own slice index - // and always returns nil, so one unhealthy signal never stops the others - // from running, and results are read back in fixed index order after - // Wait() — never in completion order. - results := make([]error, len(probes)) - g := new(errgroup.Group) - for i, probe := range probes { - g.Go(func() error { - results[i] = probe() - return nil + if ref, ok := findEnabledComponent(refs, networkOperatorComponent); ok && recipeDeclaresRDMAFabric(ref) { + probes = append(probes, gpuReadinessProbe{ + component: networkOperatorComponent, + signal: "RDMA fabric resource allocatable across the Mellanox cohort", + run: func() error { + // The polled resource is derived from the recipe's own + // NicClusterPolicy manifest (rdma/hca_shared_devices_a on AKS, + // nvidia.com/mlnxnics on OKE) so the gate waits for exactly what + // this recipe's fabric advertises. A derivation failure fails the + // gate closed — never "skip the fabric". + fabricResource, ferr := rdmaFabricResource(ctx.Ctx, ref) + if ferr != nil { + return ferr + } + return verifyRDMAFabricReady(ctx, fabricResource) + }, }) } - // Goroutines never return an error (results are recorded per-index), so Wait - // only blocks until every probe completes. - _ = g.Wait() - for _, err := range results { - capture(err) - } - - return failures, firstStructured + return probes } func findEnabledComponent(refs []recipe.ComponentRef, name string) (recipe.ComponentRef, bool) { diff --git a/validators/deployment/expected_resources_test.go b/validators/deployment/expected_resources_test.go index 8ae7cfe351..d4f506864f 100644 --- a/validators/deployment/expected_resources_test.go +++ b/validators/deployment/expected_resources_test.go @@ -19,7 +19,9 @@ import ( stderrors "errors" "slices" "strings" + "sync" "testing" + "time" "github.com/NVIDIA/aicr/pkg/chainsaw" "github.com/NVIDIA/aicr/pkg/errors" @@ -1033,10 +1035,59 @@ func TestIsRuntimeRequiredTaint(t *testing.T) { } } +// probeRendezvousTimeout bounds how long one arm of the rendezvous below waits +// for its sibling. It elapses only when the probes did NOT overlap — i.e. only +// on the path where the test is already failing — so the passing run never +// spends it. +const probeRendezvousTimeout = 10 * time.Second + +// rendezvous releases all its arms only once `want` of them have arrived, so a +// serial implementation cannot satisfy it: arm 1 would have to complete before +// arm 2 arrives, and completing requires a release that only arm 2's arrival +// can trigger. +type rendezvous struct { + mu sync.Mutex + arrived int + want int + released chan struct{} +} + +func newRendezvous(want int) *rendezvous { + return &rendezvous{want: want, released: make(chan struct{})} +} + +// arrive blocks until every arm has arrived. Late arrivals (a probe that calls +// the same API more than once) pass straight through on the closed channel. +// t.Errorf, not t.Fatalf: this runs on a probe goroutine. +func (r *rendezvous) arrive(t *testing.T, arm string) { + t.Helper() + r.mu.Lock() + r.arrived++ + if r.arrived == r.want { + close(r.released) + } + r.mu.Unlock() + + select { + case <-r.released: + case <-time.After(probeRendezvousTimeout): + t.Errorf("%s probe waited %s at the rendezvous and its sibling never arrived — the probes ran serially, not concurrently", + arm, probeRendezvousTimeout) + } +} + // TestVerifyGPUReadinessSignalsPreservesOrderConcurrently pins the two -// properties concurrency must not break: every signal reports (one failure never -// truncates its siblings), and failures come back in the fixed nodewright → DRA -// → RDMA order the firstStructuredErr precedence depends on. +// properties the fan-out must preserve end to end: every enabled signal reports +// (one failure never truncates its siblings), and failures come back in the +// fixed nodewright → DRA → RDMA order the firstStructuredErr precedence depends +// on, whichever probe finishes first. +// +// That the probes genuinely overlap is proven by +// TestRunGPUReadinessProbesOverlap, not here: both real probes reach the +// cluster through client-go fakes, and testing.Fake.Invokes holds one mutex +// across the whole reaction chain, so a barrier installed in a reactor blocks +// every other call on the same fake — including the sibling probe's — and +// self-deadlocks regardless of whether the implementation is concurrent. func TestVerifyGPUReadinessSignalsPreservesOrderConcurrently(t *testing.T) { t.Parallel() @@ -1067,6 +1118,65 @@ func TestVerifyGPUReadinessSignalsPreservesOrderConcurrently(t *testing.T) { } } +// TestRunGPUReadinessProbesOverlap proves the fan-out is concurrent rather than +// a loop that happens to produce the same results. Each probe arrives at a +// rendezvous that releases nobody until every probe has arrived, so a serial +// implementation cannot get past it: probe 1 would have to return before probe +// 2 arrives, and returning requires probe 2's arrival. +// +// Nothing sleeps on the passing path — probeRendezvousTimeout elapses only when +// the probes did not overlap, which is already a failure. Results are still +// asserted in index order to pin that they are read back by index and not in +// completion order: probe 1 is released first but deliberately returns last. +func TestRunGPUReadinessProbesOverlap(t *testing.T) { + t.Parallel() + + rv := newRendezvous(2) + firstDone := make(chan struct{}) + errFirst := errors.New(errors.ErrCodeInternal, "first probe") + errSecond := errors.New(errors.ErrCodeNotFound, "second probe") + + results := runGPUReadinessProbes([]gpuReadinessProbe{ + { + component: "first", + signal: "first signal", + run: func() error { + rv.arrive(t, "first") + // Finish after the sibling so completion order is the reverse + // of index order; the assertions below must not notice. Bounded + // for the same reason arrive is: on a serial implementation the + // sibling never runs, and an unbounded receive would hang the + // package instead of reporting a failure. + select { + case <-firstDone: + case <-time.After(probeRendezvousTimeout): + t.Errorf("first probe waited %s for the second to finish; the second never ran", probeRendezvousTimeout) + } + return errFirst + }, + }, + { + component: "second", + signal: "second signal", + run: func() error { + rv.arrive(t, "second") + close(firstDone) + return errSecond + }, + }, + }) + + if len(results) != 2 { + t.Fatalf("got %d results, want one per probe", len(results)) + } + if !stderrors.Is(results[0], errFirst) { + t.Errorf("results[0] = %v, want the first probe's error regardless of completion order", results[0]) + } + if !stderrors.Is(results[1], errSecond) { + t.Errorf("results[1] = %v, want the second probe's error", results[1]) + } +} + func stringSlicesEqual(a, b []string) bool { if len(a) != len(b) { return false @@ -1795,10 +1905,121 @@ func TestCheckExpectedResourcesFailsClosedOnExhaustedBudget(t *testing.T) { } } -// TestMarkUndispatched proves a component queued for chainsaw but never -// dispatched is reported as not evaluated rather than silently dropped — -// otherwise an operator reads a short failure list and concludes the rest of -// the cluster is fine. +// TestCheckExpectedResourcesReportsUnreachedWorkOnExhaustedBudget is the +// regression for the reporting half of issue #2473: a budget that expires +// partway through must account for the components the iteration never reached +// and the GPU probes it skipped, not just the asserts it happened to queue +// first. Under-reporting is the dangerous direction — an operator reading three +// namespace failures concludes the other six signals were fine. +// +// The context is pre-canceled, so the loop breaks on its very first guard and +// every enabled ref is unreached. Expected tally, all deterministic: +// - 3 namespace failures (verifyNamespacesActive runs before the loop and +// every namespace is absent from the empty fake clientset) +// - 2 unreached health checks (gpu-operator, network-operator; dra-driver +// carries none and must not produce a line) +// - 2 skipped GPU probes (network-operator's RDMA fabric, selected by its +// NicClusterPolicy manifest, and the DRA kubelet plugin) +// +// Before the fix the count was 3. +func TestCheckExpectedResourcesReportsUnreachedWorkOnExhaustedBudget(t *testing.T) { + t.Parallel() + + refs := []recipe.ComponentRef{ + {Name: "gpu-operator", Namespace: "gpu-ns", HealthCheckAsserts: "apiVersion: v1\nkind: Namespace\n"}, + { + Name: networkOperatorComponent, + Namespace: "network-operator", + HealthCheckAsserts: "apiVersion: v1\nkind: Namespace\n", + ManifestFiles: []string{"components/network-operator/" + nicClusterPolicyManifestMarker + ".yaml"}, + }, + {Name: draDriverComponent, Namespace: "nvidia-dra-driver"}, + } + + ctx := newDeploymentTestContext(t, nil, nil, refs) + canceled, cancel := context.WithCancel(context.Background()) + cancel() // budget already spent before the first component is examined + ctx.Ctx = canceled + + err := checkExpectedResources(ctx) + if err == nil { + t.Fatal("checkExpectedResources returned nil on an exhausted budget; it must fail closed") + } + if !strings.Contains(err.Error(), "7 issue(s) collected") { + t.Errorf("error = %q, want 7 issue(s) collected (3 namespaces + 2 unreached health checks + 2 skipped GPU probes)", + err.Error()) + } +} + +// TestEnabledGPUReadinessProbesSelection pins which enabled components select +// which probe, since markUndispatched reports the skipped set from this list +// without running any of it — a selection drift would silently shrink the +// budget-exhausted report. +func TestEnabledGPUReadinessProbesSelection(t *testing.T) { + t.Parallel() + + tests := []struct { + name string + refs []recipe.ComponentRef + want []string + }{ + { + name: "no GPU components enabled", + refs: []recipe.ComponentRef{{Name: "gpu-operator", Namespace: "gpu-ns"}}, + want: nil, + }, + { + name: "dra driver alone", + refs: []recipe.ComponentRef{{Name: draDriverComponent, Namespace: "dra-ns"}}, + want: []string{draDriverComponent}, + }, + { + name: "network operator without a NicClusterPolicy manifest selects nothing", + refs: []recipe.ComponentRef{{Name: networkOperatorComponent, Namespace: "net-ns"}}, + want: nil, + }, + { + name: "network operator with a NicClusterPolicy manifest selects the fabric probe", + refs: []recipe.ComponentRef{{ + Name: networkOperatorComponent, + Namespace: "net-ns", + ManifestFiles: []string{nicClusterPolicyManifestMarker + ".yaml"}, + }}, + want: []string{networkOperatorComponent}, + }, + { + name: "order follows the fixed nodewright → dra → rdma sequence, not ref order", + refs: []recipe.ComponentRef{ + {Name: networkOperatorComponent, Namespace: "net-ns", ManifestFiles: []string{nicClusterPolicyManifestMarker + ".yaml"}}, + {Name: draDriverComponent, Namespace: "dra-ns"}, + }, + want: []string{draDriverComponent, networkOperatorComponent}, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + ctx := newDeploymentTestContext(t, nil, nil, tt.refs) + var got []string + for _, p := range enabledGPUReadinessProbes(ctx, tt.refs) { + if p.signal == "" { + t.Errorf("probe %q has an empty signal label; the skipped-probe report needs it", p.component) + } + got = append(got, p.component) + } + if !stringSlicesEqual(got, tt.want) { + t.Errorf("enabledGPUReadinessProbes() = %v, want %v", got, tt.want) + } + }) + } +} + +// TestMarkUndispatched proves every piece of work an exhausted run left undone +// is reported as not evaluated rather than silently dropped — otherwise an +// operator reads a short failure list and concludes the rest of the cluster is +// fine. All three categories must appear: asserts queued but never dispatched, +// components the iteration never reached, and GPU probes that were skipped. // // Unit-tested against the helper rather than through checkExpectedResources: // reaching that path in an integration test needs a context that is live while @@ -1810,18 +2031,32 @@ func TestMarkUndispatched(t *testing.T) { got := markUndispatched( []string{"[expectedResources] existing failure"}, []chainsaw.ComponentAssert{{Name: "gpu-operator"}, {Name: "network-operator"}}, + []recipe.ComponentRef{ + {Name: "unreached-with-check", HealthCheckAsserts: "apiVersion: v1"}, + // No HealthCheckAsserts: there was no verdict to lose, so it must + // NOT produce a line or the report inflates the unchecked count. + {Name: "unreached-without-check"}, + }, + []gpuReadinessProbe{{component: "dra-driver", signal: "DRA kubelet plugin readiness"}}, "chainsaw dispatch", ) - if len(got) != 3 { - t.Fatalf("got %d failures, want 3 (1 pre-existing + 2 undispatched)", len(got)) + if len(got) != 5 { + t.Fatalf("got %d failures (%q), want 5 (1 pre-existing + 2 queued + 1 unreached + 1 GPU probe)", len(got), got) } for _, want := range []string{ "[chainsaw] gpu-operator: not evaluated — budget exhausted during chainsaw dispatch", "[chainsaw] network-operator: not evaluated — budget exhausted during chainsaw dispatch", + "[chainsaw] unreached-with-check: not evaluated — budget exhausted during chainsaw dispatch", + "[gpuReadiness] dra-driver (DRA kubelet plugin readiness): not evaluated — budget exhausted during chainsaw dispatch", } { if !slices.Contains(got, want) { t.Errorf("failures %q missing %q", got, want) } } + for _, f := range got { + if strings.Contains(f, "unreached-without-check") { + t.Errorf("failures %q names a component that carries no health check", got) + } + } } From 27ba63b2dc1c1dacf3c7ad3b0800c0ed986a9202 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Thu, 10 Sep 2026 13:07:45 -0700 Subject: [PATCH 16/22] docs(validator): correct the JobPlan timeout example and self-termination rule The JobPlan customization example mutated plan.CheckTimeout after BuildJobPlan, which is a no-op for AICR_CHECK_TIMEOUT because buildEnv has already baked the value into plan.Env. Set entry.Timeout before the call instead, so both the env var and the derived JobDeadline follow from it. Self-termination within AICR_CHECK_TIMEOUT is a MUST, not a SHOULD: a pod that exits on its own is no longer active, so deleteActivePods leaves it as Failed for log extraction, whereas one still running when activeDeadlineSeconds fires is deleted along with its verdict. Signed-off-by: Alex Yuskauskas --- docs/integrator/validator-extension.md | 2 +- pkg/validator/v1/README.md | 8 ++++++-- 2 files changed, 7 insertions(+), 3 deletions(-) diff --git a/docs/integrator/validator-extension.md b/docs/integrator/validator-extension.md index 225931d7dd..9cc936d6d7 100644 --- a/docs/integrator/validator-extension.md +++ b/docs/integrator/validator-extension.md @@ -244,7 +244,7 @@ ENTRYPOINT ["/check.sh"] - Must run as non-root (validator Jobs use `runAsNonRoot: true`) - Must handle the mounted data paths (`/data/snapshot/`, `/data/validation/`) -- Should self-terminate within the catalog `timeout` (published as `AICR_CHECK_TIMEOUT`) rather than rely on the Job — the Job's `activeDeadlineSeconds` is set to the catalog entry plus a fixed headroom, as a backstop for a check that never exits on its own +- **Must** self-terminate within the catalog `timeout` (published as `AICR_CHECK_TIMEOUT`) rather than rely on the Job — the Job's `activeDeadlineSeconds` is set to the catalog entry plus a fixed headroom, as a backstop for a check that never exits on its own. Self-termination is what preserves the logs: a pod that exited on its own is no longer *active*, so the Job controller's `deleteActivePods` leaves it in place as `Failed` for the orchestrator to read, whereas a pod still running when the backstop fires is deleted along with its verdict - Should write meaningful evidence to stdout for the CTRF report - Must use explicit image tags (not `:latest`) for reproducibility in external catalogs diff --git a/pkg/validator/v1/README.md b/pkg/validator/v1/README.md index bb28a05218..1744621831 100644 --- a/pkg/validator/v1/README.md +++ b/pkg/validator/v1/README.md @@ -208,7 +208,13 @@ for _, p := range groups[string(v1.PhaseConformance)] { /* … */ } ## Customizing a single plan +Change the timeout on the catalog entry, not on the returned plan. +`BuildJobPlan` bakes `AICR_CHECK_TIMEOUT` into `plan.Env` and derives +`plan.JobDeadline` from the same value, so both follow from `entry.Timeout`: + ```go +entry.Timeout = 10 * time.Minute // drives AICR_CHECK_TIMEOUT and activeDeadlineSeconds + plan, err := v1.BuildJobPlan( entry, runID, @@ -223,8 +229,6 @@ if err != nil { return err } -plan.CheckTimeout = 600 // 10 minutes -plan.JobDeadline = int64(v1.JobDeadlineFor(10 * time.Minute).Seconds()) // activeDeadlineSeconds plan.Env = append(plan.Env, corev1.EnvVar{Name: "MY_VAR", Value: "x"}) job := v1.RenderPlan(plan) From ca51304580198cc4d64e2166ff111792df8f6bf9 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Thu, 10 Sep 2026 13:26:49 -0700 Subject: [PATCH 17/22] docs(validator): bound the deadline-headroom guarantee in comments The orchestrator-vs-Job-deadline race is strictly better after the rebase, not absolute: once the ValidatorMinCompletionWait floor engages for d >= checkTimeout+180s, the Job's own activeDeadlineSeconds can fire first again. Four comments overstated the guarantee as unconditional; correct them to name the floored regime, and add a table-test case pinning that band. Signed-off-by: Alex Yuskauskas --- pkg/defaults/timeouts.go | 12 +++++++----- pkg/validator/job/deployer.go | 4 ++-- pkg/validator/v1/job_plan.go | 13 ++++++++----- pkg/validator/v1/job_plan_test.go | 22 ++++++++++++++++++---- 4 files changed, 35 insertions(+), 16 deletions(-) diff --git a/pkg/defaults/timeouts.go b/pkg/defaults/timeouts.go index 5c5e47b8a6..011936e532 100644 --- a/pkg/defaults/timeouts.go +++ b/pkg/defaults/timeouts.go @@ -1161,11 +1161,13 @@ const ( // ValidatorMinCompletionWait floors the orchestrator's Job-completion wait // once that wait has been rebased onto the Job's observed start time. The // rebase subtracts however long the create/apply response took to arrive, - // and a pathological delay would otherwise leave a zero or negative - // remainder — an orchestrator timeout reported before the check ran. One - // SIGTERM-to-SIGKILL window is the shortest span in which a Job already - // past its activeDeadlineSeconds can still stamp a terminal condition for - // the orchestrator to read. + // and the floor engages as soon as the rebased remainder drops below it — + // not only once that remainder goes zero or negative — since an unfloored + // wait that short risks reporting an orchestrator timeout before the check + // ran. One SIGTERM-to-SIGKILL window is the shortest span in which a Job + // can still stamp a terminal condition for the orchestrator to read, + // whether or not its own activeDeadlineSeconds has already elapsed by the + // time the floor engages. ValidatorMinCompletionWait = ValidatorTerminationGracePeriod // ValidatorDefaultTimeout is the default per-validator timeout if not diff --git a/pkg/validator/job/deployer.go b/pkg/validator/job/deployer.go index a62e612553..034504a252 100644 --- a/pkg/validator/job/deployer.go +++ b/pkg/validator/job/deployer.go @@ -345,8 +345,8 @@ func (d *Deployer) CleanupJob(ctx context.Context) error { // The wait is anchored to the Job's observed start time rather than to the // moment this method was called, so it and the Job's own activeDeadlineSeconds // are measured from the same origin and the orchestrator stays the tighter -// clock however long the apply response took to arrive. v1.OrchestratorWaitFor -// carries the derivation. +// clock for all but a pathologically slow apply response. v1.OrchestratorWaitFor +// carries the derivation, including where that guarantee stops holding. func (d *Deployer) WaitForCompletion(ctx context.Context, timeout time.Duration) error { waitTimeout := v1.OrchestratorWaitFor(d.jobStart, time.Now(), timeout) // pod.WaitForJobTerminal already returns structured errors with proper diff --git a/pkg/validator/v1/job_plan.go b/pkg/validator/v1/job_plan.go index 0ecbb00a69..08882c5087 100644 --- a/pkg/validator/v1/job_plan.go +++ b/pkg/validator/v1/job_plan.go @@ -211,10 +211,11 @@ func JobDeadlineFor(checkTimeout time.Duration) time.Duration { // wait to observedStart instead of to now removes that delay from the // comparison, so a caller that waits checkTimeout+defaults.ValidatorWaitBuffer // still expires before the Job's checkTimeout+defaults.ValidatorJobDeadlineHeadroom -// no matter how slow the response was. Without the rebase the effective margin -// between the two is only defaults.JobEnvelopeMargin, and a response slower -// than that lets the Job controller win and delete the still-active pod whose -// logs carry the verdict (issue #2473). +// for all but a pathologically slow response (see the floor below for where +// that stops holding). Without the rebase the effective margin between the +// two is only defaults.JobEnvelopeMargin, and a response slower than that +// lets the Job controller win and delete the still-active pod whose logs +// carry the verdict (issue #2473). // // observedStart is status.startTime when the caller has seen it, else the Job's // creationTimestamp — never later than status.startTime, so the fallback ends @@ -224,7 +225,9 @@ func JobDeadlineFor(checkTimeout time.Duration) time.Duration { // The result is capped at that same unrebased budget, because apiserver clock // skew can place observedStart in the caller's future, and floored at // defaults.ValidatorMinCompletionWait so a pathological response delay does not -// produce a wait too short to observe a terminal condition. +// produce a wait too short to observe a terminal condition. Once the floor +// engages, the Job's own deadline can fire first again — later than without +// the rebase, but no longer guaranteed to trail it. func OrchestratorWaitFor(observedStart, now time.Time, checkTimeout time.Duration) time.Duration { budget := checkTimeout + defaults.ValidatorWaitBuffer if observedStart.IsZero() { diff --git a/pkg/validator/v1/job_plan_test.go b/pkg/validator/v1/job_plan_test.go index b55d4b5bb5..b426f25a4b 100644 --- a/pkg/validator/v1/job_plan_test.go +++ b/pkg/validator/v1/job_plan_test.go @@ -1391,10 +1391,12 @@ func TestOrchestratorWaitForRebasesOntoJobStart(t *testing.T) { applyDelay time.Duration // how long the apply response took to arrive want time.Duration // floored marks the case where the remainder was clamped to - // defaults.ValidatorMinCompletionWait. The Job deadline is already in - // the past by then, so the fit-inside-the-deadline invariant below - // cannot hold and is not asserted; the floor's job is only to leave - // enough wall clock to read the terminal condition Kubernetes stamped. + // defaults.ValidatorMinCompletionWait. That can happen well before the + // Job deadline is reached, not only once it is already in the past + // (see the cases below for both); either way the fit-inside-the- + // deadline invariant is not guaranteed to hold, so floored cases skip + // it. The floor's job is only to leave enough wall clock to read the + // terminal condition Kubernetes stamped. floored bool }{ { @@ -1422,6 +1424,18 @@ func TestOrchestratorWaitForRebasesOntoJobStart(t *testing.T) { want: defaults.ValidatorMinCompletionWait, // 30s floored: true, }, + { + // applyDelay=8m15s falls inside [checkTimeout+180s, checkTimeout+210s) + // = [8m, 8m30s): the floor still engages (remaining would be + // negative), but jobDeadline (8m30s) has not elapsed yet when the + // wait begins. The floored 30s wait ends at 8m45s, past jobDeadline, + // so the Job's own deadline — not this wait — is what ends up + // bounding how long the still-active pod survives. + name: "floor engages before the Job deadline, but the floored wait outlives it", + applyDelay: 8*time.Minute + 15*time.Second, // 495s, inside [8m, 8m30s) + want: defaults.ValidatorMinCompletionWait, // 30s + floored: true, + }, { // Apiserver clock skew can place the observed start in the // caller's future; the wait must not exceed the nominal budget. From 71632c385a8a331ab857cdbe76b540055e8ba95f Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Fri, 11 Sep 2026 13:00:56 -0700 Subject: [PATCH 18/22] docs(validator): condition the ADR's clock-ordering claim on startup Signed-off-by: Alex Yuskauskas --- docs/design/002-validatorv2-adr.md | 16 +++++++++++++--- 1 file changed, 13 insertions(+), 3 deletions(-) diff --git a/docs/design/002-validatorv2-adr.md b/docs/design/002-validatorv2-adr.md index 1cf3f254ef..7a7eea4442 100644 --- a/docs/design/002-validatorv2-adr.md +++ b/docs/design/002-validatorv2-adr.md @@ -111,7 +111,8 @@ Every validator container: Each validator runs as a K8s Job with: - `backoffLimit: 0` — no retries - `activeDeadlineSeconds` — catalog `timeout` plus `defaults.ValidatorJobDeadlineHeadroom`, - so the check's own budget always expires first (see Timeout and Termination below) + so the check's own budget expires first unless container startup outruns that + headroom (see Timeout and Termination below) - `terminationGracePeriodSeconds: 30` — time between SIGTERM and SIGKILL - `ttlSecondsAfterFinished: 3600` — 1 hour retention for debugging - `restartPolicy: Never` @@ -145,8 +146,17 @@ Created once per run via Server-Side Apply, cleaned up at end. ### Timeout and Termination Four timeout layers protect against hangs. The first three are ordered so the -check's own budget is always the tightest — the ordering that closes issue -#2473 (see below): +check's own budget is the tightest — the ordering that closes issue #2473 (see +below). Clocks 1 and 3 start at different moments, so that ordering is not +unconditional: clock 1 begins when the validator container's first instruction +runs, while clock 3 begins at the Job's start time. Container startup — +scheduling plus image pull — therefore eats into the headroom, and a startup +slower than `defaults.ValidatorJobDeadlineHeadroom` lets clock 3 fire first. +Kubernetes then marks the Job `Failed/DeadlineExceeded` and deletes the still-active +pod, which is the pre-#2473 behaviour: the phase still fails closed, but the +check's own diagnosis is lost. The headroom is sized as +`defaults.K8sPodReadyTimeout` plus margin to cover ordinary startup; it is a +budget, not a guarantee. 1. **Check budget** (catalog `timeout`, published as `AICR_CHECK_TIMEOUT`): the validator's own parent context. A well-behaved check cancels and exits on From c8773d00d8c4bebb14944f0981dd9006d7ce0643 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Mon, 14 Sep 2026 09:53:43 -0700 Subject: [PATCH 19/22] fix(validator): hold the Job-completion wait inside the Job deadline MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit OrchestratorWaitFor floored the rebased wait at ValidatorMinCompletionWait without checking how much of the Job's own deadline was left. The time until Kubernetes fires is remaining + JobEnvelopeMargin, so the floor won only while remaining > -30s; past that the function returned a 30s wait it could compute would outlive the deadline, and the Job controller deleted the still-active pod whose logs carry the verdict (issue #2473). Bound every branch by JobDeadlineFor(checkTimeout) measured from the same observedStart anchor the Job controller uses, so the two derivations cannot drift, and end the wait at least ValidatorPreDeadlineMargin (new, 1s) before it. When that bound is not positive the deadline is already gone and no shorter wait can save the pod, so the floor is returned anyway: a zero or negative wait would expire WaitForJobTerminal's context before its fast-path Get could observe the already-terminal Job, degrading a Failed/DeadlineExceeded outcome into an infrastructure error. Rewrite the comments that ca513045 hedged with "for all but a pathologically slow response" — the wait no longer outlives a deadline it can still beat — and correct the JobPlan.JobDeadline claim that the check "always" terminates first, which container startup slower than the headroom can still break. The table test case that expected the floored 30s at an 8m15s apply delay encoded the bug; it now expects 14s. Added coverage for a deadline nearer than the floor, both boundaries, and an elapsed deadline (asserting the returned wait is positive so the terminal Get can run). Signed-off-by: Alex Yuskauskas --- pkg/defaults/timeouts.go | 23 ++++++-- pkg/validator/job/deployer.go | 8 +-- pkg/validator/v1/job_plan.go | 57 +++++++++++++------- pkg/validator/v1/job_plan_test.go | 90 ++++++++++++++++++++++--------- 4 files changed, 126 insertions(+), 52 deletions(-) diff --git a/pkg/defaults/timeouts.go b/pkg/defaults/timeouts.go index 011936e532..7b1ba5636c 100644 --- a/pkg/defaults/timeouts.go +++ b/pkg/defaults/timeouts.go @@ -1164,12 +1164,27 @@ const ( // and the floor engages as soon as the rebased remainder drops below it — // not only once that remainder goes zero or negative — since an unfloored // wait that short risks reporting an orchestrator timeout before the check - // ran. One SIGTERM-to-SIGKILL window is the shortest span in which a Job - // can still stamp a terminal condition for the orchestrator to read, - // whether or not its own activeDeadlineSeconds has already elapsed by the - // time the floor engages. + // ran. The floor does not license outrunning the Job's own deadline: + // v1.OrchestratorWaitFor caps it to ValidatorPreDeadlineMargin short of + // that deadline while the deadline is still ahead. Once it is not, the + // floored wait is all that remains, and one SIGTERM-to-SIGKILL window is + // the shortest span in which the orchestrator can still read the terminal + // condition Kubernetes stamped on the Job it has already ended. ValidatorMinCompletionWait = ValidatorTerminationGracePeriod + // ValidatorPreDeadlineMargin is how far short of the Job's + // activeDeadlineSeconds v1.OrchestratorWaitFor holds the orchestrator's + // Job-completion wait. That wait exists to read the check's own verdict, + // and the Job deadline destroys it: the Job controller deletes the + // still-active pod whose logs carry it (issue #2473). A wait ending at the + // same instant as the deadline leaves which of the two lands first to + // scheduling chance, so the margin is subtracted to make the ordering + // strict. It is a tie-breaker rather than a budget for any work, sized to + // exceed the resolution at which the two events can be distinguished while + // staying negligible against ValidatorMinCompletionWait, the shortest wait + // it ever trims. + ValidatorPreDeadlineMargin = 1 * time.Second + // ValidatorDefaultTimeout is the default per-validator timeout if not // specified in the catalog. Used as fallback only. ValidatorDefaultTimeout = 5 * time.Minute diff --git a/pkg/validator/job/deployer.go b/pkg/validator/job/deployer.go index 034504a252..fc96fda3b1 100644 --- a/pkg/validator/job/deployer.go +++ b/pkg/validator/job/deployer.go @@ -344,9 +344,11 @@ func (d *Deployer) CleanupJob(ctx context.Context) error { // // The wait is anchored to the Job's observed start time rather than to the // moment this method was called, so it and the Job's own activeDeadlineSeconds -// are measured from the same origin and the orchestrator stays the tighter -// clock for all but a pathologically slow apply response. v1.OrchestratorWaitFor -// carries the derivation, including where that guarantee stops holding. +// are measured from the same origin, and v1.OrchestratorWaitFor caps the result +// short of that deadline. The orchestrator therefore stays the tighter clock +// for every apply response that arrives while the Job deadline is still more +// than defaults.ValidatorPreDeadlineMargin away. That function carries the +// derivation, including what the wait is still good for once it is not. func (d *Deployer) WaitForCompletion(ctx context.Context, timeout time.Duration) error { waitTimeout := v1.OrchestratorWaitFor(d.jobStart, time.Now(), timeout) // pod.WaitForJobTerminal already returns structured errors with proper diff --git a/pkg/validator/v1/job_plan.go b/pkg/validator/v1/job_plan.go index 08882c5087..c018fe7237 100644 --- a/pkg/validator/v1/job_plan.go +++ b/pkg/validator/v1/job_plan.go @@ -80,8 +80,11 @@ type JobPlan struct { CheckTimeout int64 // JobDeadline is the Job's activeDeadlineSeconds. It exceeds CheckTimeout - // by defaults.ValidatorJobDeadlineHeadroom so the check always terminates - // itself first and its pod survives for log extraction. Unlike + // by defaults.ValidatorJobDeadlineHeadroom, which budgets for the container + // startup that CheckTimeout's clock does not cover, so the check normally + // terminates itself first and its pod survives for log extraction; a + // startup slower than the headroom spends that budget and lets the Job + // controller delete the still-active pod instead. Unlike // CheckTimeout, RenderPlan reads this field directly, so it is not purely // informational — but leaving it at its zero value yields a Job whose // activeDeadlineSeconds is 0, which the Job controller treats as already @@ -209,38 +212,54 @@ func JobDeadlineFor(checkTimeout time.Duration) time.Duration { // activeDeadlineSeconds from the Job's status.startTime, whereas a caller can // only begin waiting once the create/apply response reaches it. Anchoring the // wait to observedStart instead of to now removes that delay from the -// comparison, so a caller that waits checkTimeout+defaults.ValidatorWaitBuffer -// still expires before the Job's checkTimeout+defaults.ValidatorJobDeadlineHeadroom -// for all but a pathologically slow response (see the floor below for where -// that stops holding). Without the rebase the effective margin between the -// two is only defaults.JobEnvelopeMargin, and a response slower than that -// lets the Job controller win and delete the still-active pod whose logs -// carry the verdict (issue #2473). +// comparison: a wait of checkTimeout+defaults.ValidatorWaitBuffer measured from +// observedStart ends defaults.JobEnvelopeMargin before the Job's +// checkTimeout+defaults.ValidatorJobDeadlineHeadroom measured from the same +// point. Without the rebase that margin is instead consumed by the response +// delay, and a response slower than it lets the Job controller win and delete +// the still-active pod whose logs carry the verdict (issue #2473). // // observedStart is status.startTime when the caller has seen it, else the Job's // creationTimestamp — never later than status.startTime, so the fallback ends // the wait earlier rather than later. A zero observedStart means no start time -// was observed at all and yields the unrebased budget. +// was observed at all and yields the unrebased budget; it is the one result the +// Job-deadline bound below cannot cover, since that bound needs the same anchor. // -// The result is capped at that same unrebased budget, because apiserver clock -// skew can place observedStart in the caller's future, and floored at -// defaults.ValidatorMinCompletionWait so a pathological response delay does not -// produce a wait too short to observe a terminal condition. Once the floor -// engages, the Job's own deadline can fire first again — later than without -// the rebase, but no longer guaranteed to trail it. +// The rebased remainder is capped at that unrebased budget, because apiserver +// clock skew can place observedStart in the caller's future, and floored at +// defaults.ValidatorMinCompletionWait so a slow response does not produce a +// wait too short to observe a terminal condition. +// +// Every branch is then bounded by the Job's own deadline, derived from the same +// anchor by JobDeadlineFor so the two cannot drift: the returned wait ends at +// least defaults.ValidatorPreDeadlineMargin before it, so no result — the floor +// included — outlives a deadline it can still beat. When that bound is not +// positive, because the deadline has already elapsed or is within the margin of +// firing, no shorter wait can keep the pod alive, so the floor is returned +// anyway. Its only remaining job is to leave WaitForJobTerminal's fast-path Get +// room to observe the already-terminal Job, so the caller reports the Job's +// Failed/DeadlineExceeded outcome instead of the infrastructure error a zero or +// negative wait would produce by expiring that Get's context before it runs. func OrchestratorWaitFor(observedStart, now time.Time, checkTimeout time.Duration) time.Duration { budget := checkTimeout + defaults.ValidatorWaitBuffer if observedStart.IsZero() { return budget } + + insideDeadline := observedStart.Add(JobDeadlineFor(checkTimeout)).Sub(now) - + defaults.ValidatorPreDeadlineMargin + if insideDeadline <= 0 { + return defaults.ValidatorMinCompletionWait + } + remaining := observedStart.Add(budget).Sub(now) if remaining > budget { - return budget + remaining = budget } if remaining < defaults.ValidatorMinCompletionWait { - return defaults.ValidatorMinCompletionWait + remaining = defaults.ValidatorMinCompletionWait } - return remaining + return min(remaining, insideDeadline) } // BuildJobPlan creates a JobPlan from a validator entry. diff --git a/pkg/validator/v1/job_plan_test.go b/pkg/validator/v1/job_plan_test.go index b426f25a4b..206d7fbb6f 100644 --- a/pkg/validator/v1/job_plan_test.go +++ b/pkg/validator/v1/job_plan_test.go @@ -1374,30 +1374,34 @@ func TestBuildResources_NilOrEmptyUsesDefaults(t *testing.T) { // is only defaults.JobEnvelopeMargin, and a slower response lets the Job // controller fire first and delete the still-active pod holding the verdict. // -// Each case asserts the property that matters — observedStart + wait must land -// strictly before observedStart + JobDeadlineFor(checkTimeout), i.e. the whole +// Each case asserts the property that matters — the wait must end strictly +// before observedStart + JobDeadlineFor(checkTimeout), i.e. the whole // orchestrator wait fits inside the Job's own deadline measured from the same -// origin. +// origin. That now holds for the floored cases too, which is what the +// deadline bound in OrchestratorWaitFor added; the sole exception is a +// deadline already gone by the time the wait begins, where no wait can keep +// the pod alive. func TestOrchestratorWaitForRebasesOntoJobStart(t *testing.T) { t.Parallel() const checkTimeout = 5 * time.Minute budget := checkTimeout + defaults.ValidatorWaitBuffer // 5m + 2m30s = 7m30s jobDeadline := JobDeadlineFor(checkTimeout) // 5m + 3m30s = 8m30s + floor := defaults.ValidatorMinCompletionWait // 30s + margin := defaults.ValidatorPreDeadlineMargin // 1s start := time.Date(2026, 9, 8, 12, 0, 0, 0, time.UTC) tests := []struct { name string applyDelay time.Duration // how long the apply response took to arrive want time.Duration - // floored marks the case where the remainder was clamped to - // defaults.ValidatorMinCompletionWait. That can happen well before the - // Job deadline is reached, not only once it is already in the past - // (see the cases below for both); either way the fit-inside-the- - // deadline invariant is not guaranteed to hold, so floored cases skip - // it. The floor's job is only to leave enough wall clock to read the - // terminal condition Kubernetes stamped. - floored bool + // deadlineGone marks the cases where the Job deadline has already + // elapsed, or sits within margin of firing, by the time the wait + // begins. The fit-inside-the-deadline assertion is not meaningful + // there — the pod is gone either way — so those cases assert instead + // that the wait is still positive, which is what lets + // WaitForJobTerminal's fast-path Get read the terminal Job. + deadlineGone bool }{ { name: "instant apply response leaves the full budget", @@ -1419,22 +1423,49 @@ func TestOrchestratorWaitForRebasesOntoJobStart(t *testing.T) { want: budget - 90*time.Second, // 6m }, { - name: "pathological delay is floored, not driven negative", - applyDelay: budget + time.Hour, - want: defaults.ValidatorMinCompletionWait, // 30s - floored: true, + // 7m59s: the remainder is already negative so the floor engages, + // and the floored 30s is the longest wait that still ends margin + // short of the 8m30s deadline. The boundary case for the bound. + name: "floor fits inside the Job deadline by exactly the margin", + applyDelay: jobDeadline - floor - margin, // 7m59s + want: floor, }, { - // applyDelay=8m15s falls inside [checkTimeout+180s, checkTimeout+210s) - // = [8m, 8m30s): the floor still engages (remaining would be - // negative), but jobDeadline (8m30s) has not elapsed yet when the - // wait begins. The floored 30s wait ends at 8m45s, past jobDeadline, - // so the Job's own deadline — not this wait — is what ends up - // bounding how long the still-active pod survives. - name: "floor engages before the Job deadline, but the floored wait outlives it", - applyDelay: 8*time.Minute + 15*time.Second, // 495s, inside [8m, 8m30s) - want: defaults.ValidatorMinCompletionWait, // 30s - floored: true, + // One second later the floor no longer fits, so the deadline — + // not the floor — sets the wait. + name: "deadline one second nearer than the floor caps the wait", + applyDelay: jobDeadline - floor, // 8m + want: floor - margin, // 29s + }, + { + // The case that motivated the bound: 8m15s leaves 15s until the + // 8m30s deadline, and the pre-fix floor returned 30s — a wait the + // function could compute would outlive the deadline it exists to + // beat, handing the still-active pod (and its verdict) to the Job + // controller's deleteActivePods. + name: "floor would outlive the Job deadline, so the wait is capped short of it", + applyDelay: 8*time.Minute + 15*time.Second, // 495s, inside [8m, 8m30s) + want: 15*time.Second - margin, // 14s + }, + { + // Inside the margin: no positive wait both fits and is worth + // issuing, so the floor comes back to serve the fast-path Get. + name: "deadline within the pre-deadline margin returns the floor", + applyDelay: jobDeadline - margin, // 8m29s + want: floor, + deadlineGone: true, + }, + { + name: "deadline exactly elapsed returns the floor", + applyDelay: jobDeadline, // 8m30s + want: floor, + deadlineGone: true, + }, + { + name: "pathological delay is floored, not driven negative", + applyDelay: budget + time.Hour, + want: floor, + deadlineGone: true, }, { // Apiserver clock skew can place the observed start in the @@ -1454,7 +1485,14 @@ func TestOrchestratorWaitForRebasesOntoJobStart(t *testing.T) { t.Errorf("OrchestratorWaitFor(start, start+%v, %v) = %v, want %v", tt.applyDelay, checkTimeout, got, tt.want) } - if tt.floored { + if tt.deadlineGone { + // A zero or negative wait would expire the context before + // WaitForJobTerminal's initial Get could observe the + // already-terminal Job, turning its verdict into an + // infrastructure error. + if got <= 0 { + t.Errorf("wait past the Job deadline = %v, want a positive wait for the terminal Get", got) + } return } // The invariant the fix exists to hold: the orchestrator's wait, From 432eb84db136251b64b68c846461849c69a73d75 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Mon, 14 Sep 2026 09:53:43 -0700 Subject: [PATCH 20/22] docs(validator): name both paths that put the Job deadline first The clock-ordering caveat attributed Job-first termination only to container startup exceeding the headroom. A sufficiently delayed create/apply response engaged ValidatorMinCompletionWait and reached the same lost-verdict outcome by the other route. Name both, and state the post-fix truth for each: OrchestratorWaitFor now bounds every result at ValidatorPreDeadlineMargin short of clock 3 computed from the same start time, so a late response costs the wait its length rather than its ordering, while container startup remains live because the check's context cannot begin before its container does. Signed-off-by: Alex Yuskauskas --- docs/design/002-validatorv2-adr.md | 33 ++++++++++++++++++++++-------- 1 file changed, 24 insertions(+), 9 deletions(-) diff --git a/docs/design/002-validatorv2-adr.md b/docs/design/002-validatorv2-adr.md index 7a7eea4442..317f25b7de 100644 --- a/docs/design/002-validatorv2-adr.md +++ b/docs/design/002-validatorv2-adr.md @@ -147,16 +147,29 @@ Created once per run via Server-Side Apply, cleaned up at end. Four timeout layers protect against hangs. The first three are ordered so the check's own budget is the tightest — the ordering that closes issue #2473 (see -below). Clocks 1 and 3 start at different moments, so that ordering is not -unconditional: clock 1 begins when the validator container's first instruction -runs, while clock 3 begins at the Job's start time. Container startup — -scheduling plus image pull — therefore eats into the headroom, and a startup +below). The three clocks do not all start at the same moment, and two of those +offsets have put clock 3 ahead of an inner clock; only the first is still live. + +Container startup is the live one. Clock 1 begins when the validator +container's first instruction runs, while clock 3 begins at the Job's start +time, so scheduling plus image pull eats into the headroom, and a startup slower than `defaults.ValidatorJobDeadlineHeadroom` lets clock 3 fire first. Kubernetes then marks the Job `Failed/DeadlineExceeded` and deletes the still-active pod, which is the pre-#2473 behaviour: the phase still fails closed, but the -check's own diagnosis is lost. The headroom is sized as -`defaults.K8sPodReadyTimeout` plus margin to cover ordinary startup; it is a -budget, not a guarantee. +check's own diagnosis is lost. No offset applied to clock 2 removes this path, +because the check's context cannot start before its container does. The +headroom is sized as `defaults.K8sPodReadyTimeout` plus margin to cover +ordinary startup; it is a budget, not a guarantee. + +A slow create/apply response delays clock 2's start alone. Past +`defaults.ValidatorWaitBuffer` of delay the rebased wait would go negative and +`defaults.ValidatorMinCompletionWait` floors it, and a floor measured from that +late a start used to run past clock 3 — the same lost-verdict outcome, reached +by the other route. `v1.OrchestratorWaitFor` now bounds every result, floor +included, at `defaults.ValidatorPreDeadlineMargin` short of clock 3 computed +from the same start time, so a late response costs the wait its length rather +than its ordering. Once clock 3 has already fired, the wait is only there to +read the terminal Job the controller left behind. 1. **Check budget** (catalog `timeout`, published as `AICR_CHECK_TIMEOUT`): the validator's own parent context. A well-behaved check cancels and exits on @@ -173,8 +186,10 @@ budget, not a guarantee. been running for however long the apply response took: a response slower than that lets clock 3 fire first and delete the still-active pod. `v1.OrchestratorWaitFor` carries the derivation; it caps the result at the un-rebased budget (apiserver - clock skew can place the start time in the CLI's future) and floors it at - `defaults.ValidatorMinCompletionWait`. + clock skew can place the start time in the CLI's future), floors it at + `defaults.ValidatorMinCompletionWait`, and holds every result + `defaults.ValidatorPreDeadlineMargin` short of clock 3 below, measured from + that same start time. 3. **Job `activeDeadlineSeconds`** (catalog timeout + `defaults.ValidatorJobDeadlineHeadroom`, 3m30s): K8s sends SIGTERM, then SIGKILL after `terminationGracePeriodSeconds` (30s), From a9d69866f98ae1e59d6867d56fa4bf05db98c7ee Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Tue, 15 Sep 2026 16:31:20 -0700 Subject: [PATCH 21/22] fix(validator): report expected resources an exhausted budget skipped markUndispatched gated every unreached component on HealthCheckAsserts, so a ref declaring only expectedResources produced no line at all: the budget expired between components, the loop never ran helper.VerifyResource for them, and the report came back looking complete while part of the recipe's deployment contract carried no verdict. Three shipped overlays and the gb200 training example declare expectedResources, so the shape is live. Report the two kinds of work an unreached ref carries independently -- a [chainsaw] line when it has a registry health check, and an [expectedResources] line per declared resource, tagged like the lines the loop itself emits so both read the same in the failure list. TestCheckExpectedResourcesReportsUnreachedExpectedResources drives the gap through checkExpectedResources with the budget expiring mid-run rather than before it: a fake-clientset reactor cancels inside the first component's own verification, which is what deterministically leaves a later component unexamined. It reported 3 issues before this change and 5 after. Signed-off-by: Alex Yuskauskas --- validators/deployment/expected_resources.go | 41 +++--- .../deployment/expected_resources_test.go | 117 ++++++++++++++++-- 2 files changed, 134 insertions(+), 24 deletions(-) diff --git a/validators/deployment/expected_resources.go b/validators/deployment/expected_resources.go index 853eab86d7..0af76fd5be 100644 --- a/validators/deployment/expected_resources.go +++ b/validators/deployment/expected_resources.go @@ -202,9 +202,10 @@ func pollUntilStable(ctx *validators.Context, label string, probe func() error, // budgetExhausted, mark every piece of unevaluated work, print the accumulated // failures, and fail closed (issue #2473). Unevaluated work is reported in // three parts, all via markUndispatched: chainsaw asserts already queued when -// the loop broke, the health checks carried by enabledRefs entries the loop -// never reached, and the GPU readiness probes the enabled component set -// selects. Anything less understates how much of the cluster went unchecked. +// the loop broke, the health checks and expected resources carried by +// enabledRefs entries the loop never reached, and the GPU readiness probes the +// enabled component set selects. Anything less understates how much of the +// cluster went unchecked. // // Once budgetExhausted is set the GPU probes are skipped rather than run. // Their poll loops observe ctx.Ctx, but the work ahead of the first poll is not @@ -250,9 +251,9 @@ func checkExpectedResources(ctx *validators.Context) error { var budgetExhausted string // unreachedRefs are the enabledRefs the loop below never examined because - // the budget went first. Their health checks were never queued, so - // markUndispatched has to name them separately from chainsawAsserts or they - // vanish from the report entirely. + // the budget went first. Neither their health checks nor their expected + // resources were ever evaluated, so markUndispatched has to name them + // separately from chainsawAsserts or they vanish from the report entirely. var unreachedRefs []recipe.ComponentRef failures = append(failures, verifyNamespacesActive(ctx, enabledRefs)...) @@ -425,11 +426,17 @@ func enabledComponentRefs(refs []recipe.ComponentRef) []recipe.ComponentRef { // markUndispatched appends a not-evaluated line for every piece of work the // exhausted run left undone: each assert queued but never handed to chainsaw, -// each health check on a component the iteration never reached, and each GPU -// readiness probe skipped rather than run. Reporting them explicitly is what -// stops a truncated run from reading as a mostly-healthy cluster: the operator -// sees which components carry no verdict rather than inferring their absence -// means "fine". +// each health check and expected resource on a component the iteration never +// reached, and each GPU readiness probe skipped rather than run. Reporting them +// explicitly is what stops a truncated run from reading as a mostly-healthy +// cluster: the operator sees which components carry no verdict rather than +// inferring their absence means "fine". +// +// The two kinds of work an unreached ref carries are reported independently. +// A component can declare expectedResources without a registry health check — +// the loop would have verified them via helper.VerifyResource all the same — so +// gating the expectedResources lines on HealthCheckAsserts would drop part of +// the recipe's deployment contract from a report that otherwise reads complete. // // unreached and asserts are disjoint — a ref only reaches asserts by being // examined, which is what unreached excludes — so no component is named twice. @@ -449,11 +456,15 @@ func markUndispatched( "[chainsaw] %s: not evaluated — budget exhausted during %s", a.Name, stage)) } for _, ref := range unreached { - if ref.HealthCheckAsserts == "" { - continue + if ref.HealthCheckAsserts != "" { + failures = append(failures, fmt.Sprintf( + "[chainsaw] %s: not evaluated — budget exhausted during %s", ref.Name, stage)) + } + for _, er := range ref.ExpectedResources { + failures = append(failures, fmt.Sprintf( + "[expectedResources] %s %s/%s (%s): not evaluated — budget exhausted during %s", + er.Kind, er.Namespace, er.Name, ref.Name, stage)) } - failures = append(failures, fmt.Sprintf( - "[chainsaw] %s: not evaluated — budget exhausted during %s", ref.Name, stage)) } for _, p := range gpuProbes { failures = append(failures, fmt.Sprintf( diff --git a/validators/deployment/expected_resources_test.go b/validators/deployment/expected_resources_test.go index d4f506864f..2a61c78158 100644 --- a/validators/deployment/expected_resources_test.go +++ b/validators/deployment/expected_resources_test.go @@ -1951,6 +1951,79 @@ func TestCheckExpectedResourcesReportsUnreachedWorkOnExhaustedBudget(t *testing. } } +// TestCheckExpectedResourcesReportsUnreachedExpectedResources covers the +// component shape the unreached-work report used to drop entirely: one that +// declares expectedResources and carries no registry health check. Gating the +// not-evaluated lines on HealthCheckAsserts let a budget that expired between +// components omit part of the recipe's deployment contract from a report that +// otherwise read complete. +// +// Unlike the sibling test above, the budget here expires *during* the run +// rather than before it, which is what puts a later component on the unreached +// path while an earlier one was fully evaluated. The reactor makes that +// deterministic: the fake clientset dispatches it synchronously inside +// first-component's own helper.VerifyResource, so the loop's next guard is +// guaranteed to see a dead context with later-component still unexamined. +// +// Expected tally, all deterministic: +// - 2 namespace failures (verifyNamespacesActive runs before the loop and +// neither namespace exists in the empty fake clientset) +// - 1 expectedResources failure for first-component's Deployment, which the +// loop did reach +// - 2 not-evaluated lines for later-component's two expected resources +// +// Before the fix the count was 3. +func TestCheckExpectedResourcesReportsUnreachedExpectedResources(t *testing.T) { + t.Parallel() + + refs := []recipe.ComponentRef{ + { + Name: "first-component", + Namespace: "first-ns", + ExpectedResources: []recipe.ExpectedResource{ + {Kind: "Deployment", Namespace: "first-ns", Name: "first-dep"}, + }, + }, + { + Name: "later-component", + Namespace: "later-ns", + ExpectedResources: []recipe.ExpectedResource{ + {Kind: "Deployment", Namespace: "later-ns", Name: "later-dep"}, + {Kind: "DaemonSet", Namespace: "later-ns", Name: "later-ds"}, + }, + }, + } + + ctx := newDeploymentTestContext(t, nil, nil, refs) + budget, cancel := context.WithCancel(context.Background()) + defer cancel() + ctx.Ctx = budget + + fake, ok := ctx.Clientset.(*k8sfake.Clientset) + if !ok { + t.Fatalf("Clientset is %T, want *k8sfake.Clientset", ctx.Clientset) + } + // Spend the budget inside first-component's own verification. Returning + // handled=false falls through to the object tracker, so the Deployment + // still reports its normal NotFound. + fake.PrependReactor("get", "deployments", func(clienttesting.Action) (bool, runtime.Object, error) { + cancel() + return false, nil, nil + }) + + err := checkExpectedResources(ctx) + if err == nil { + t.Fatal("checkExpectedResources returned nil on an exhausted budget; it must fail closed") + } + if !stderrors.Is(err, errors.New(errors.ErrCodeTimeout, "")) { + t.Errorf("error = %v, want ErrCodeTimeout", err) + } + if !strings.Contains(err.Error(), "5 issue(s) collected") { + t.Errorf("error = %q, want 5 issue(s) collected (2 namespaces + 1 verified resource + 2 unreached resources)", + err.Error()) + } +} + // TestEnabledGPUReadinessProbesSelection pins which enabled components select // which probe, since markUndispatched reports the skipped set from this list // without running any of it — a selection drift would silently shrink the @@ -2018,8 +2091,14 @@ func TestEnabledGPUReadinessProbesSelection(t *testing.T) { // TestMarkUndispatched proves every piece of work an exhausted run left undone // is reported as not evaluated rather than silently dropped — otherwise an // operator reads a short failure list and concludes the rest of the cluster is -// fine. All three categories must appear: asserts queued but never dispatched, -// components the iteration never reached, and GPU probes that were skipped. +// fine. All four categories must appear: asserts queued but never dispatched, +// health checks and expectedResources on components the iteration never +// reached, and GPU probes that were skipped. +// +// The unreached-with-both and unreached-with-resources refs pin that the two +// kinds of work are reported independently: a component declaring +// expectedResources and no registry health check still has a deployment +// contract the run never verified. // // Unit-tested against the helper rather than through checkExpectedResources: // reaching that path in an integration test needs a context that is live while @@ -2033,21 +2112,41 @@ func TestMarkUndispatched(t *testing.T) { []chainsaw.ComponentAssert{{Name: "gpu-operator"}, {Name: "network-operator"}}, []recipe.ComponentRef{ {Name: "unreached-with-check", HealthCheckAsserts: "apiVersion: v1"}, - // No HealthCheckAsserts: there was no verdict to lose, so it must - // NOT produce a line or the report inflates the unchecked count. - {Name: "unreached-without-check"}, + { + Name: "unreached-with-both", + HealthCheckAsserts: "apiVersion: v1", + ExpectedResources: []recipe.ExpectedResource{ + {Kind: "Deployment", Namespace: "both-ns", Name: "both-dep"}, + }, + }, + { + Name: "unreached-with-resources", + ExpectedResources: []recipe.ExpectedResource{ + {Kind: "Deployment", Namespace: "res-ns", Name: "res-dep"}, + {Kind: "DaemonSet", Namespace: "res-ns", Name: "res-ds"}, + }, + }, + // Neither health check nor expectedResources: there was no verdict + // to lose, so it must NOT produce a line or the report inflates the + // unchecked count. + {Name: "unreached-without-work"}, }, []gpuReadinessProbe{{component: "dra-driver", signal: "DRA kubelet plugin readiness"}}, "chainsaw dispatch", ) - if len(got) != 5 { - t.Fatalf("got %d failures (%q), want 5 (1 pre-existing + 2 queued + 1 unreached + 1 GPU probe)", len(got), got) + if len(got) != 9 { + t.Fatalf("got %d failures (%q), want 9 (1 pre-existing + 2 queued + 2 unreached health checks + 3 unreached resources + 1 GPU probe)", + len(got), got) } for _, want := range []string{ "[chainsaw] gpu-operator: not evaluated — budget exhausted during chainsaw dispatch", "[chainsaw] network-operator: not evaluated — budget exhausted during chainsaw dispatch", "[chainsaw] unreached-with-check: not evaluated — budget exhausted during chainsaw dispatch", + "[chainsaw] unreached-with-both: not evaluated — budget exhausted during chainsaw dispatch", + "[expectedResources] Deployment both-ns/both-dep (unreached-with-both): not evaluated — budget exhausted during chainsaw dispatch", + "[expectedResources] Deployment res-ns/res-dep (unreached-with-resources): not evaluated — budget exhausted during chainsaw dispatch", + "[expectedResources] DaemonSet res-ns/res-ds (unreached-with-resources): not evaluated — budget exhausted during chainsaw dispatch", "[gpuReadiness] dra-driver (DRA kubelet plugin readiness): not evaluated — budget exhausted during chainsaw dispatch", } { if !slices.Contains(got, want) { @@ -2055,8 +2154,8 @@ func TestMarkUndispatched(t *testing.T) { } } for _, f := range got { - if strings.Contains(f, "unreached-without-check") { - t.Errorf("failures %q names a component that carries no health check", got) + if strings.Contains(f, "unreached-without-work") { + t.Errorf("failures %q names a component that carries no unevaluated work", got) } } } From 0fc9fb714cf9c8ff5577bbceb14c1354bc1ec421 Mon Sep 17 00:00:00 2001 From: Alex Yuskauskas Date: Tue, 15 Sep 2026 16:31:28 -0700 Subject: [PATCH 22/22] docs(validator): name the observed-start fallback in the CLI wait origin The exit-code note said the CLI wait is measured from "the Job's own start time", but observedJobStart falls back to creationTimestamp whenever the apiserver has not yet stamped status.startTime -- which is the normal case in the create/apply response the wait is anchored on. Name both, and state the direction: creationTimestamp is never later than status.startTime, so the fallback only ever ends the wait earlier, which keeps the "deliberately shorter than activeDeadlineSeconds" claim in the same sentence true rather than weakening it. The ADR already documented the fallback this way (docs/design/002-validatorv2-adr.md); this brings the user guide in line. Signed-off-by: Alex Yuskauskas --- docs/user/validation.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docs/user/validation.md b/docs/user/validation.md index 02c0604936..8e88996f2c 100644 --- a/docs/user/validation.md +++ b/docs/user/validation.md @@ -876,7 +876,7 @@ error codes (see [`pkg/errors/exitcode.go`](https://github.com/NVIDIA/aicr/blob/ > **Important:** two subtleties to be aware of when gating a pipeline on exit code: > -> 1. Both `failed` and `other` are blocking. A phase whose status is `other` — the check produced no usable verdict, e.g. a crash, an OOM, or a Job that failed for a non-deadline reason with its pod already gone — drives the same non-zero exit as `failed` — an inconclusive check fails closed rather than passing silently. `--fail-on-error=false` suppresses **both** result-driven exits (the run reports the outcomes in the CTRF report and exits 0); it does not distinguish `failed` from `other`. A validator Job killed on `activeDeadlineSeconds` normally reports `failed` rather than `other`: its terminal `Failed/DeadlineExceeded` condition is a verdict, so the result names the deadline instead of the missing pod. One narrow exception remains — the CLI waits the catalog timeout plus `ValidatorWaitBuffer` (2m30s) for the Job to become terminal — measured from the Job's own start time, so it shares an origin with the Job's clock — a window that is deliberately shorter than the Job's own `activeDeadlineSeconds` (catalog timeout plus `ValidatorJobDeadlineHeadroom`, 3m30s), so a validator whose pod is still running when the CLI's wait expires exhausts the wait before the deadline condition is ever stamped. Such a run falls back to the CLI-wait path and still reports `other`. +> 1. Both `failed` and `other` are blocking. A phase whose status is `other` — the check produced no usable verdict, e.g. a crash, an OOM, or a Job that failed for a non-deadline reason with its pod already gone — drives the same non-zero exit as `failed` — an inconclusive check fails closed rather than passing silently. `--fail-on-error=false` suppresses **both** result-driven exits (the run reports the outcomes in the CTRF report and exits 0); it does not distinguish `failed` from `other`. A validator Job killed on `activeDeadlineSeconds` normally reports `failed` rather than `other`: its terminal `Failed/DeadlineExceeded` condition is a verdict, so the result names the deadline instead of the missing pod. One narrow exception remains — the CLI waits the catalog timeout plus `ValidatorWaitBuffer` (2m30s) for the Job to become terminal — measured from the Job's observed start time (`status.startTime` when the apiserver has stamped it, otherwise `creationTimestamp`, which is never later and so only ever ends the wait earlier), so it shares an origin with the Job's clock — a window that is deliberately shorter than the Job's own `activeDeadlineSeconds` (catalog timeout plus `ValidatorJobDeadlineHeadroom`, 3m30s), so a validator whose pod is still running when the CLI's wait expires exhausts the wait before the deadline condition is ever stamped. Such a run falls back to the CLI-wait path and still reports `other`. > 2. Exit 5 is narrower than it sounds. A timeout **inside** a check's own logic (DynamoGraphDeployment not ready, inference endpoint never healthy, AIPerf Job pod-wait deadline) surfaces as a failed phase, not as a structured `ErrCodeTimeout`, so the CLI exits **8**. So does a per-validator wait deadline: `runPhase` hands that error to the timeout handler and records the outcome as a check result rather than propagating it, which is the same path the wait-exhaustion exception in note 1 takes. The rule, rather than a list of sources: exit 5 applies whenever an `ErrCodeTimeout` reaches the top-level CLI. A timeout that is converted into a check result instead — whether raised inside a check or by a per-validator wait — surfaces as exit 8. Scripts that gate on validation outcome should treat **any non-zero code** as