Skip to content

Commit 7f4d7f2

Browse files
committed
fix(validator): diagnose expiry from the current probe and claim only what was observed
An incomplete probe's expiry reported the previous iteration's reason, so a first probe delayed past the allowance produced the generic fallback instead of naming the missing object. Use the current probe's result. The late-success reason also asserted when the installation became complete, which the wait never measures; it only observes completeness after expiry. Signed-off-by: Yuan Chen <yuanchen97@gmail.com>
1 parent c0d31a9 commit 7f4d7f2

2 files changed

Lines changed: 95 additions & 3 deletions

File tree

validators/performance/trainer_ensure_test.go

Lines changed: 85 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -565,3 +565,88 @@ func TestWaitForDeclaredTrainer_LateSuccessDoesNotOutrunTheDeadline(t *testing.T
565565
t.Errorf("reason claims nothing was found, but the probe returned complete: %v", err)
566566
}
567567
}
568+
569+
// TestWaitForDeclaredTrainer_ExpiryNamesTheProbeThatJustRan pins the reason reported
570+
// when the allowance expires on an *incomplete* probe.
571+
//
572+
// The recheck before accepting a result runs on every iteration, not only the
573+
// successful ones. When the probe that just ran came back incomplete, its own
574+
// finding — the object that is actually missing — is what the operator needs. An
575+
// earlier revision carried the previous iteration's result into the diagnosis, so
576+
// the first probe of a wait reported the zero value and the operator got a generic
577+
// "no complete installation was found" instead of the missing CRD.
578+
//
579+
// Stalling the CRD read past the allowance and answering NotFound produces exactly
580+
// that shape: one probe, incomplete, deadline already gone.
581+
func TestWaitForDeclaredTrainer_ExpiryNamesTheProbeThatJustRan(t *testing.T) {
582+
oldTimeout, oldInterval := trainerInstallWaitTimeout, trainerInstallPollInterval
583+
trainerInstallWaitTimeout = 20 * time.Millisecond
584+
trainerInstallPollInterval = time.Millisecond
585+
defer func() {
586+
trainerInstallWaitTimeout, trainerInstallPollInterval = oldTimeout, oldInterval
587+
}()
588+
589+
client := newTrainerFakeClient()
590+
client.PrependReactor("get", "customresourcedefinitions",
591+
func(k8stesting.Action) (bool, runtime.Object, error) {
592+
// Outlive the allowance, then answer NotFound. A missing CRD short-circuits
593+
// the probe, so it returns incomplete with no error and the recheck below
594+
// is the next thing that runs.
595+
time.Sleep(60 * time.Millisecond)
596+
return true, nil, apierrors.NewNotFound(
597+
schema.GroupResource{Group: "apiextensions.k8s.io", Resource: "customresourcedefinitions"},
598+
"trainjobs.trainer.kubeflow.org")
599+
})
600+
601+
_, err := waitForDeclaredTrainer(context.Background(), client)
602+
if err == nil {
603+
t.Fatal("expected an error once the allowance expired with the installation incomplete")
604+
}
605+
if !stderrors.Is(err, aicrErrors.New(aicrErrors.ErrCodeNotFound, "")) {
606+
t.Errorf("error code = %v, want ErrCodeNotFound: the deadline expired locally "+
607+
"with the parent still live", err)
608+
}
609+
if !strings.Contains(err.Error(), "CRD trainjobs.trainer.kubeflow.org is missing") {
610+
t.Errorf("expiry did not name the object the probe just found missing: %v", err)
611+
}
612+
if strings.Contains(err.Error(), "no complete installation was found") {
613+
t.Errorf("expiry fell back to the generic reason even though the probe that just "+
614+
"ran reported a specific missing object: %v", err)
615+
}
616+
}
617+
618+
// TestWaitForDeclaredTrainer_LateSuccessClaimsOnlyWhatWasObserved pins the wording of
619+
// the late-success reason to what the code can actually know.
620+
//
621+
// The recheck learns that the probe returned complete and that the deadline has
622+
// already passed. It cannot know *when* the installation became complete — only when
623+
// it was observed to be. Claiming it "became complete after the allowance expired"
624+
// asserts a transition time nobody measured, and would mislead an operator whose
625+
// Trainer was healthy all along behind a slow apiserver.
626+
func TestWaitForDeclaredTrainer_LateSuccessClaimsOnlyWhatWasObserved(t *testing.T) {
627+
oldTimeout, oldInterval := trainerInstallWaitTimeout, trainerInstallPollInterval
628+
trainerInstallWaitTimeout = 20 * time.Millisecond
629+
trainerInstallPollInterval = time.Millisecond
630+
defer func() {
631+
trainerInstallWaitTimeout, trainerInstallPollInterval = oldTimeout, oldInterval
632+
}()
633+
634+
client := newTrainerFakeClient(completeTrainerInstall()...)
635+
client.PrependReactor("get", "services",
636+
func(k8stesting.Action) (bool, runtime.Object, error) {
637+
time.Sleep(60 * time.Millisecond)
638+
return false, nil, nil
639+
})
640+
641+
_, err := waitForDeclaredTrainer(context.Background(), client)
642+
if err == nil {
643+
t.Fatal("expected an error once the allowance expired")
644+
}
645+
if strings.Contains(err.Error(), "became complete") {
646+
t.Errorf("reason asserts when the installation became complete, which the wait "+
647+
"never measured; it only observed completeness after expiry: %v", err)
648+
}
649+
if !strings.Contains(err.Error(), "observed complete only after the allowance expired") {
650+
t.Errorf("reason does not state what was actually observed: %v", err)
651+
}
652+
}

validators/performance/trainer_lifecycle.go

Lines changed: 10 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -652,11 +652,18 @@ func waitForDeclaredTrainer(ctx context.Context, dynamicClient dynamic.Interface
652652
// Report why from *this* probe, not the previous one. When ok is true the
653653
// installation is complete, so reusing last would blame a missing object the
654654
// probe just found — sending an operator to look for something that is there,
655-
// when the real finding is a rollout slower than its budget.
656-
expired := last
655+
// when the real finding is a rollout slower than its budget. When ok is false
656+
// the current probe's own finding is the specific object still missing, which
657+
// the previous iteration's result would replace with a staler one — or, on the
658+
// first probe, with the zero value's generic fallback.
659+
//
660+
// The complete case claims only what was observed. The wait never measures when
661+
// the installation became complete, only when it saw that it was, so wording it
662+
// as a transition would assert a time nobody read.
663+
expired := install
657664
if ok {
658665
expired = trainerInstall{
659-
Incomplete: "the installation became complete, but only after the allowance expired",
666+
Incomplete: "the installation was observed complete only after the allowance expired",
660667
}
661668
}
662669
if verdict := classifyPollExpiry(ctx, pollCtx, expired); verdict != nil {

0 commit comments

Comments
 (0)