From c3ae47f9a017b6e7644f928ef4baeea3521a4a91 Mon Sep 17 00:00:00 2001 From: Tomba Leishangthem <10569680+tomba7@users.noreply.github.com> Date: Thu, 27 Aug 2026 08:12:27 -0700 Subject: [PATCH 1/2] test(itest): capture drainage state on integration-test failure [DO NOT MERGE] --- .github/workflows/test-integration.yml | 12 +- internal/tests/internal/env_helpers.go | 5 + internal/tests/internal/integration_test.go | 12 ++ internal/tests/internal/validation_helpers.go | 179 ++++++++++++++++++ 4 files changed, 206 insertions(+), 2 deletions(-) diff --git a/.github/workflows/test-integration.yml b/.github/workflows/test-integration.yml index d4dd1c87..abf7aa54 100644 --- a/.github/workflows/test-integration.yml +++ b/.github/workflows/test-integration.yml @@ -57,7 +57,12 @@ jobs: test-integration: name: Run Integration Tests runs-on: ubuntu-latest - + # TRIAGE ONLY (#542) -- do not merge. + strategy: + fail-fast: false + matrix: + shard: [1, 2, 3, 4, 5, 6, 7, 8, 9, 10] + steps: - name: Checkout code uses: actions/checkout@3d3c42e5aac5ba805825da76410c181273ba90b1 # v7.0.1 @@ -108,7 +113,10 @@ jobs: if: always() uses: actions/upload-artifact@ea165f8d65b6e75b540449e92b4886f43607fa02 # v4.6.2 with: - name: test-results + # Per-shard name: artifact names must be unique within a run, otherwise 9 of + # the 10 jobs fail on "an artifact with this name already exists" and read as + # test failures. (#542 triage) + name: test-results-${{ matrix.shard }} path: | cover.out bin/ diff --git a/internal/tests/internal/env_helpers.go b/internal/tests/internal/env_helpers.go index 20e62955..039ed1be 100644 --- a/internal/tests/internal/env_helpers.go +++ b/internal/tests/internal/env_helpers.go @@ -44,6 +44,11 @@ const ( testControllerIdentityPrefix = "test-controller-identity" testControllerIdentitySuffix = "123" testControllerIdentity = testControllerIdentityPrefix + "/" + testControllerIdentitySuffix + + // How long postMortemDrainageWatch keeps observing after a failure, and how often. + // Only ever spent on an already-failing test. (#542) + postMortemBudget = 5 * time.Minute + postMortemInterval = 5 * time.Second ) // setupKubebuilderAssets sets up the KUBEBUILDER_ASSETS environment variable if not already set diff --git a/internal/tests/internal/integration_test.go b/internal/tests/internal/integration_test.go index 8d39b6ac..d2f3c334 100644 --- a/internal/tests/internal/integration_test.go +++ b/internal/tests/internal/integration_test.go @@ -1043,6 +1043,14 @@ func testWorkerDeploymentCreation( ExpectedDeploymentReplicas: tc.GetExpectedDeploymentReplicas(), } + diagOnFailure = func(label string) { + logRolloutDiagnostics(t, ctx, env, twd, label, true) + postMortemDrainageWatch(t, ctx, env, twd, + k8s.ComputeVersionedDeploymentName(twd.Name, k8s.ComputeBuildID(twd)), + postMortemBudget, postMortemInterval) + } + defer func() { diagOnFailure = nil }() + makePreliminaryStatusTrue(ctx, t, env, twd, tc.GetPreviouslyCurrentImages()) // verify that temporal state matches the preliminary status, to confirm that makePreliminaryStatusTrue worked @@ -1058,6 +1066,8 @@ func testWorkerDeploymentCreation( f(twd) } + logRolloutDiagnostics(t, ctx, env, twd, "pre-create", true) + t.Log("Creating a WorkerDeployment") if err := k8sClient.Create(ctx, twd); err != nil { t.Fatalf("failed to create WorkerDeployment: %v", err) @@ -1073,6 +1083,8 @@ func testWorkerDeploymentCreation( } } + logRolloutDiagnostics(t, ctx, env, twd, "twd-created", false) + // Hook: runs after TWD creation but before waiting for the target Deployment. // Use this to assert blocking behaviour and then unblock the rollout. if f := tc.GetPostTWDCreateFunc(); f != nil { diff --git a/internal/tests/internal/validation_helpers.go b/internal/tests/internal/validation_helpers.go index 6136783c..e17a8be4 100644 --- a/internal/tests/internal/validation_helpers.go +++ b/internal/tests/internal/validation_helpers.go @@ -31,6 +31,7 @@ func waitForExpectedTargetDeployment(t *testing.T, twd *temporaliov1alpha1.Worke deadline := time.Now().Add(timeout) deploymentName := k8s.ComputeVersionedDeploymentName(twd.Name, k8s.ComputeBuildID(twd)) namespace := twd.Namespace + ticks := 0 for time.Now().Before(deadline) { var deployment appsv1.Deployment @@ -51,7 +52,14 @@ func waitForExpectedTargetDeployment(t *testing.T, twd *temporaliov1alpha1.Worke return } time.Sleep(1 * time.Second) + // Cheap k8s-only snapshot while blocked, so a failure shows whether the + // gating state was evolving or frozen. Diagnostic only (#542). + if ticks++; ticks%10 == 0 { + logRolloutDiagnostics(t, ctx, env, twd, fmt.Sprintf("waiting-%ds", ticks), false) + } } + logRolloutDiagnostics(t, ctx, env, twd, "timeout", true) + postMortemDrainageWatch(t, ctx, env, twd, deploymentName, postMortemBudget, postMortemInterval) t.Fatalf("failed to wait for deployment: timeout waiting for deployment %s in namespace %s", deploymentName, namespace) } @@ -478,6 +486,9 @@ func waitForEvent( }) } +// diagOnFailure ... +var diagOnFailure func(label string) + func eventually(t *testing.T, timeout, interval time.Duration, check func() error) { deadline := time.Now().Add(timeout) var lastErr error @@ -490,6 +501,9 @@ func eventually(t *testing.T, timeout, interval time.Duration, check func() erro time.Sleep(interval) } if lastErr != nil { + if diagOnFailure != nil { + diagOnFailure("eventually-failed") + } t.Fatalf("eventually failed after %s: %v", timeout, lastErr) } } @@ -569,3 +583,168 @@ func assertWRTControllerOwnerRef( t.Errorf("WRT %s/%s missing controller owner reference to TWD %s (refs: %+v)", namespace, wrtName, twdName, wrt.OwnerReferences) } + +// logRolloutDiagnostics dumps the state +func logRolloutDiagnostics( + t *testing.T, + ctx context.Context, + env testhelpers.TestEnv, + twd *temporaliov1alpha1.WorkerDeployment, + label string, + describeTemporal bool, +) { + t.Helper() + + if describeTemporal { + wdName := k8s.ComputeWorkerDeploymentName(twd) + handle := env.Ts.GetDefaultClient().WorkerDeploymentClient().GetHandle(wdName) + resp, err := handle.Describe(ctx, sdkclient.WorkerDeploymentDescribeOptions{}) + if err != nil { + t.Logf("DIAG[%s] temporal describe %s failed: %v", label, wdName, err) + } else { + rc := resp.Info.RoutingConfig + cur, ramp := "", "" + if rc.CurrentVersion != nil { + cur = rc.CurrentVersion.BuildID + } + if rc.RampingVersion != nil { + ramp = rc.RampingVersion.BuildID + } + t.Logf("DIAG[%s] temporal %s: current=%s ramping=%s versions=%d", + label, wdName, cur, ramp, len(resp.Info.VersionSummaries)) + for _, vs := range resp.Info.VersionSummaries { + t.Logf("DIAG[%s] temporal version %-14s drainage=%v", label, vs.Version.BuildID, vs.DrainageStatus) + } + } + } + + var live temporaliov1alpha1.WorkerDeployment + if err := env.K8sClient.Get(ctx, types.NamespacedName{Name: twd.Name, Namespace: twd.Namespace}, &live); client.IgnoreNotFound(err) == nil && err != nil { + t.Logf("DIAG[%s] TWD not created yet", label) + } else if err != nil { + t.Logf("DIAG[%s] get TWD %s failed: %v", label, twd.Name, err) + } else { + ineligible := 0 + for _, dv := range live.Status.DeprecatedVersions { + if !dv.EligibleForDeletion { + ineligible++ + } + } + cur := "" + if live.Status.CurrentVersion != nil { + cur = live.Status.CurrentVersion.BuildID + } + t.Logf("DIAG[%s] TWD status: current=%s target=%s(%s) versionCount=%d deprecated=%d ineligible=%d (cap=%d, blocked=%v)", + label, cur, live.Status.TargetVersion.BuildID, live.Status.TargetVersion.Status, + live.Status.VersionCount, len(live.Status.DeprecatedVersions), ineligible, + testMaxVersionsIneligibleForDeletion, ineligible >= testMaxVersionsIneligibleForDeletion) + for _, dv := range live.Status.DeprecatedVersions { + t.Logf("DIAG[%s] deprecated %-14s status=%-14s eligibleForDeletion=%v", label, dv.BuildID, dv.Status, dv.EligibleForDeletion) + } + } + + var deps appsv1.DeploymentList + if err := env.K8sClient.List(ctx, &deps, client.InNamespace(twd.Namespace)); err != nil { + t.Logf("DIAG[%s] list deployments failed: %v", label, err) + return + } + for _, d := range deps.Items { + owned := false + for _, or := range d.OwnerReferences { + if or.UID == twd.UID { + owned = true + } + } + if !owned { + continue + } + var specReplicas int32 + if d.Spec.Replicas != nil { + specReplicas = *d.Spec.Replicas + } + t.Logf("DIAG[%s] k8s deployment %-42s buildID=%-14s spec.replicas=%d status.replicas=%d", + label, d.Name, d.Labels[k8s.BuildIDLabel], specReplicas, d.Status.Replicas) + } +} + +// postMortemDrainageWatch keeps watching after the test has already given up +func postMortemDrainageWatch( + t *testing.T, + ctx context.Context, + env testhelpers.TestEnv, + twd *temporaliov1alpha1.WorkerDeployment, + deploymentName string, + budget time.Duration, + interval time.Duration, +) { + t.Helper() + + wdName := k8s.ComputeWorkerDeploymentName(twd) + handle := env.Ts.GetDefaultClient().WorkerDeploymentClient().GetHandle(wdName) + + if probe, err := handle.Describe(ctx, sdkclient.WorkerDeploymentDescribeOptions{}); err == nil { + stuck := false + for _, vs := range probe.Info.VersionSummaries { + if vs.DrainageStatus == sdkclient.WorkerDeploymentVersionDrainageStatusDraining { + stuck = true + } + } + if !stuck { + t.Logf("DIAG[post-mortem] no version is in Draining; nothing to watch") + return + } + } + + start := time.Now() + deadline := start.Add(budget) + lastDrainage := map[string]sdkclient.WorkerDeploymentVersionDrainageStatus{} + deploymentSeen := false + var firstFlip, deploymentAt time.Duration + sawFlip := false + + t.Logf("DIAG[post-mortem] watching for up to %s at %s intervals (test has already failed)", budget, interval) + + for time.Now().Before(deadline) { + elapsed := time.Since(start).Truncate(time.Second) + + resp, err := handle.Describe(ctx, sdkclient.WorkerDeploymentDescribeOptions{}) + if err != nil { + t.Logf("DIAG[post-mortem] t=+%s describe failed: %v", elapsed, err) + } else { + for _, vs := range resp.Info.VersionSummaries { + prev, seen := lastDrainage[vs.Version.BuildID] + if !seen { + t.Logf("DIAG[post-mortem] t=+%s %-14s drainage=%v", elapsed, vs.Version.BuildID, vs.DrainageStatus) + } else if prev != vs.DrainageStatus { + t.Logf("DIAG[post-mortem] t=+%s %-14s drainage %v -> %v <-- TRANSITION", elapsed, vs.Version.BuildID, prev, vs.DrainageStatus) + if !sawFlip && vs.DrainageStatus == sdkclient.WorkerDeploymentVersionDrainageStatusDrained { + firstFlip, sawFlip = elapsed, true + } + } + lastDrainage[vs.Version.BuildID] = vs.DrainageStatus + } + } + + if !deploymentSeen { + var deployment appsv1.Deployment + if err := env.K8sClient.Get(ctx, types.NamespacedName{Name: deploymentName, Namespace: twd.Namespace}, &deployment); err == nil { + deploymentSeen, deploymentAt = true, elapsed + t.Logf("DIAG[post-mortem] t=+%s deployment %s CREATED <-- controller unblocked", elapsed, deploymentName) + } + } + + if sawFlip && deploymentSeen { + break // both questions answered; no reason to keep the run alive + } + time.Sleep(interval) + } + + switch { + case sawFlip && deploymentSeen: + t.Logf("DIAG[post-mortem] VERDICT: backoff, not latched -- drained at +%s, controller created the deployment at +%s", firstFlip, deploymentAt) + case sawFlip: + t.Logf("DIAG[post-mortem] VERDICT: drainage recovered at +%s but the deployment never appeared within %s", firstFlip, budget) + default: + t.Logf("DIAG[post-mortem] VERDICT: latched -- no version reached Drained within %s; drainage evaluation appears to have stopped", budget) + } +} From 7efbcaf7b8495a0e4c4ad6fa0e9009083126c119 Mon Sep 17 00:00:00 2001 From: Tomba Leishangthem <10569680+tomba7@users.noreply.github.com> Date: Thu, 27 Aug 2026 08:56:59 -0700 Subject: [PATCH 2/2] test(itest): raise go test timeout and shorten post-mortem budget [DO NOT MERGE] --- Makefile | 5 ++++- internal/tests/internal/env_helpers.go | 2 +- 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/Makefile b/Makefile index 06a3ba45..73e94864 100644 --- a/Makefile +++ b/Makefile @@ -228,9 +228,12 @@ test-unit: envtest helm-dependency-build ## Run unit tests and webhook integrati KUBEBUILDER_ASSETS="$(shell $(ENVTEST) use $(ENVTEST_K8S_VERSION) --bin-dir $(LOCALBIN) -p path)" go test ./... -coverprofile cover.out .PHONY: test-integration +# -timeout: Go's default is 10m and the suite already runs ~9m in CI, so any added wait +# (e.g. the #542 triage diagnostics) panics the whole binary rather than failing a single +# subtest. 30m matches what ci/run-integration-tests.sh already passes. test-integration: manifests generate envtest ## Run integration tests against local Temporal dev server. @echo "Running integration tests..." - KUBEBUILDER_ASSETS="$(shell $(ENVTEST) use $(ENVTEST_K8S_VERSION) --bin-dir $(LOCALBIN) -p path)" go test -v -tags test_dep ./internal/tests/internal -run TestIntegration + KUBEBUILDER_ASSETS="$(shell $(ENVTEST) use $(ENVTEST_K8S_VERSION) --bin-dir $(LOCALBIN) -p path)" go test -v -tags test_dep ./internal/tests/internal -run TestIntegration -timeout 30m ##@ Build diff --git a/internal/tests/internal/env_helpers.go b/internal/tests/internal/env_helpers.go index 039ed1be..f20c8c72 100644 --- a/internal/tests/internal/env_helpers.go +++ b/internal/tests/internal/env_helpers.go @@ -47,7 +47,7 @@ const ( // How long postMortemDrainageWatch keeps observing after a failure, and how often. // Only ever spent on an already-failing test. (#542) - postMortemBudget = 5 * time.Minute + postMortemBudget = 2 * time.Minute postMortemInterval = 5 * time.Second )