[oadp-1.6] test: unpend two kdm restore PIts, fixing bugs found via live e2e validation

Makefile

@@ -943,7 +943,15 @@ TEST_VIRT ?= false
 # https://github.com/openshift/oadp-operator/issues/2413 option B.
 TEST_VIRT_KDM_ORIGIN := $(origin TEST_VIRT_KDM)
 TEST_VIRT_KDM ?= false
-HCO_INDEX_TAG ?= 1.18.0
+# Defaults to the upstream kubevirt/hyperconverged-cluster-index "nightly"
+# moving tag rather than a pinned release, so every virt/kdm e2e run picks up
+# kubevirt/kubevirt fixes (e.g. kubevirt/kubevirt#18949) automatically as soon
+# as they land in a nightly build, with no version bump needed on our side.
+# The OLM channel nightly publishes (e.g. "candidate-v1.20") is discovered
+# live from the catalog's PackageManifest, not guessed from this tag's shape,
+# so unpinned tags like "nightly" work correctly here. Override to a pinned
+# release (e.g. "1.18.0") for a reproducible/stable run instead.
+HCO_INDEX_TAG ?= nightly
 # hcp
 TEST_HCP ?= false
 TEST_HCP_EXTERNAL ?= false

build/ci-Dockerfile

@@ -25,6 +25,12 @@ RUN export KV_VERSION=$(curl --retry 5 --retry-delay 5 -s https://storage.google
     chmod +x virtctl && \
     mv virtctl /usr/local/bin/
 
-RUN go mod download && \
+# retry: confirmed live in CI -- proxy.golang.org intermittently drops the
+# module fetch mid-transfer ("stream error: stream ID NNNN; INTERNAL_ERROR;
+# received from peer"), failing the whole image build over a transient proxy
+# hiccup unrelated to any code change. `go mod download` has no built-in
+# retry flag, so wrap it the same way as the curl fetches above.
+RUN retry() { for i in 1 2 3 4 5; do "$@" && return 0; echo "retrying ($i/5): $*" >&2; sleep 5; done; return 1; }; \
+    retry go mod download && \
     mkdir -p $(go env GOCACHE) && \
     chmod -R 777 ./ $(go env GOCACHE) $(go env GOPATH)

tests/e2e/backup_restore_suite_test.go

@@ -421,7 +421,17 @@ func gatherLogs(brCase BackupRestoreCase, installTime time.Time, report ginkgo.S
 func deleteNamespace(namespace string) {
 	err := lib.DeleteNamespace(kubernetesClientForSuiteRun, namespace)
 	gomega.Expect(err).ToNot(gomega.HaveOccurred())
-	gomega.Eventually(lib.IsNamespaceDeleted(kubernetesClientForSuiteRun, namespace), time.Minute*5, time.Second*5).Should(gomega.BeTrue())
+	// Clear any stuck VirtualMachineBackup finalizers (workaround for kubevirt#18724)
+	// before waiting for namespace termination. A spec that hits a known-bug skip
+	// path (see lib.CheckIfFlakeOccurred) unwinds via ginkgo.Skip before reaching
+	// its own namespace cleanup (e.g. IsNamespaceDeletedClearingStuckVMBFinalizers
+	// in virt_backup_restore_suite_test.go), leaving this shared AfterEach path as
+	// the only place left to do it -- confirmed live: without this, the plain
+	// IsNamespaceDeleted wait times out after 5m on a namespace whose VMB never
+	// got a real completed status (same still-open kubevirt/kubevirt#18949 disease
+	// as VMBHasNoConditions). Harmless no-op for namespaces with no VMBs.
+	vmbClearer := &lib.VirtOperator{Dynamic: dynamicClientForSuiteRun}
+	gomega.Eventually(vmbClearer.IsNamespaceDeletedClearingStuckVMBFinalizers(kubernetesClientForSuiteRun, namespace), time.Minute*5, time.Second*5).Should(gomega.BeTrue())
 }
 
 var _ = ginkgo.Describe("Backup and restore tests", ginkgo.Ordered, func() {

tests/e2e/lib/apps.go

@@ -10,6 +10,7 @@ import (
 	"os/exec"
 	"path/filepath"
 	"reflect"
+	"regexp"
 	"sort"
 	"strings"
 	"time"
@@ -377,6 +378,24 @@ func PrintNamespaceEventsAfterTime(c *kubernetes.Clientset, namespace string, st
 	}
 }
 
+// GetNamespaceEventMessages returns "Reason: Message" for every event
+// currently in namespace, for feeding into CheckIfFlakeOccurred alongside
+// pod logs -- some known-flake signatures (e.g. a controller's own emitted
+// Kubernetes Event on an object it owns) only ever show up as an Event, not
+// in any pod's log output.
+func GetNamespaceEventMessages(c *kubernetes.Clientset, namespace string) []string {
+	events, err := c.CoreV1().Events(namespace).List(context.Background(), metav1.ListOptions{})
+	if err != nil {
+		log.Printf("could not list events in namespace %s for flake-detection: %v", namespace, err)
+		return nil
+	}
+	messages := make([]string, 0, len(events.Items))
+	for _, event := range events.Items {
+		messages = append(messages, fmt.Sprintf("%s: %s", event.Reason, event.Message))
+	}
+	return messages
+}
+
 func RunMustGather(artifact_dir string, clusterClient client.Client) error {
 	// Use MUST_GATHER_IMAGE env var, default to quay.io/konveyor/oadp-must-gather:oadp-1.6
 	// For version-specific testing: MUST_GATHER_IMAGE=quay.io/konveyor/oadp-must-gather:oadp-1.5
@@ -429,12 +448,69 @@ func RunMustGather(artifact_dir string, clusterClient client.Client) error {
 	mustGatherSummaryText := string(mustGatherSummaryContent)
 
 	if !strings.Contains(mustGatherSummaryText, "No errors happened or were found while running OADP must-gather") {
-		return errors.New("expected no errors in must-gather Errors section")
+		if !mustGatherErrorsAreOnlyKnownBenignWarnings(mustGatherSummaryText) {
+			return errors.New("expected no errors in must-gather Errors section")
+		}
 	}
 
 	return nil
 }
 
+// mustGatherKnownBenignErrorPatterns are must-gather "Errors" section lines
+// that are purely informational -- the summary generator flags any DPA using
+// spec.unsupportedOverrides at all, regardless of which key or why, since
+// that field is inherently "unsupported" by design. A test intentionally
+// using it (e.g. to override kdm-controller's image with a candidate fix
+// build before it merges upstream) is not itself an error condition, and
+// treating it as one broke every e2e job's must-gather check the moment any
+// suite's DPA carried an UnsupportedOverrides entry -- confirmed live on
+// oadp-operator PR#2404, where a single test-time override in
+// e2e_suite_test.go's shared dpaCR broke unrelated CLI e2e jobs across
+// multiple OCP versions. Any OTHER line in the Errors section still fails
+// the check below -- only this specific, expected caveat is tolerated.
+var mustGatherKnownBenignErrorPatterns = []*regexp.Regexp{
+	regexp.MustCompile(`is using \*\*unsupportedOverrides\*\*`),
+}
+
+// mustGatherErrorsAreOnlyKnownBenignWarnings extracts the "## Errors" section
+// of the must-gather summary and reports whether every non-blank line in it
+// matches a known-benign pattern above. Returns false (i.e. a real error is
+// present) if the section can't be found at all, to fail safe.
+func mustGatherErrorsAreOnlyKnownBenignWarnings(summary string) bool {
+	lines := strings.Split(summary, "\n")
+	start := -1
+	for i, line := range lines {
+		if strings.TrimSpace(line) == "## Errors" {
+			start = i + 1
+			break
+		}
+	}
+	if start == -1 {
+		return false
+	}
+
+	for _, line := range lines[start:] {
+		trimmed := strings.TrimSpace(line)
+		if trimmed == "" {
+			continue
+		}
+		if strings.HasPrefix(trimmed, "## ") {
+			break
+		}
+		matched := false
+		for _, p := range mustGatherKnownBenignErrorPatterns {
+			if p.MatchString(trimmed) {
+				matched = true
+				break
+			}
+		}
+		if !matched {
+			return false
+		}
+	}
+	return true
+}
+
 // VerifyBackupRestoreData verifies if app ready before backup and after restore to compare data.
 // skipReadyz skips the post-restore readyz endpoint check (use for VM-based tests where the
 // app route is not directly reachable from the test harness).

tests/e2e/lib/apps_test.go

@@ -0,0 +1,52 @@
+package lib
+
+import "testing"
+
+// realMustGatherSummaryUnsupportedOverridesOnly is the actual "## Errors"
+// section (and the section immediately following it) captured from a real
+// CI failure: openshift/oadp-operator PR#2404's ci/prow/5.1-e2e-test-cli-aws
+// run (2093596791407644672), which failed with "expected no errors in
+// must-gather Errors section" purely because the shared dpaCR carried a
+// spec.unsupportedOverrides entry (a test-time kdm-controller image
+// override, unrelated to the CLI suite that failed).
+const realMustGatherSummaryUnsupportedOverridesOnly = `## Errors
+
+⚠️ DataProtectionApplication **ts-velero-test** in **openshift-adp** namespace is using **unsupportedOverrides**
+
+
+
+## Cluster information
+
+| Cluster ID | OpenShift version | Cloud provider | Architecture |
+| ---------- | ----------------- | -------------- | ------------ |
+| 65162e20 | 5.1.0-0.nightly-2026-08-27-012048 | AWS | linux/amd64 |
+`
+
+func Test_mustGatherErrorsAreOnlyKnownBenignWarnings_realUnsupportedOverridesCapture(t *testing.T) {
+	if !mustGatherErrorsAreOnlyKnownBenignWarnings(realMustGatherSummaryUnsupportedOverridesOnly) {
+		t.Fatalf("expected the real captured unsupportedOverrides-only Errors section to be treated as benign")
+	}
+}
+
+func Test_mustGatherErrorsAreOnlyKnownBenignWarnings_realErrorStillFails(t *testing.T) {
+	summary := `## Errors
+
+⚠️ DataProtectionApplication **ts-velero-test** in **openshift-adp** namespace is using **unsupportedOverrides**
+❌ Velero pod is in CrashLoopBackOff
+
+## Cluster information
+`
+	if mustGatherErrorsAreOnlyKnownBenignWarnings(summary) {
+		t.Fatalf("expected a genuine error line alongside the benign warning to still be treated as a real error")
+	}
+}
+
+func Test_mustGatherErrorsAreOnlyKnownBenignWarnings_noErrorsSectionFailsSafe(t *testing.T) {
+	summary := `## Cluster information
+
+| Cluster ID | OpenShift version |
+`
+	if mustGatherErrorsAreOnlyKnownBenignWarnings(summary) {
+		t.Fatalf("expected a missing Errors section to fail safe (treated as a real error)")
+	}
+}

tests/e2e/lib/flakes.go

@@ -33,11 +33,59 @@ type FlakePattern struct {
 	StringSearchPattern string
 }
 
+// FilterLogLinesContaining returns only the lines of logs that contain at
+// least one of the given substrings. kdm-controller runs as a single shared
+// pod across every spec in a suite run (it's never restarted between specs),
+// so a raw, unfiltered pod-log fetch mixes lines from whichever OTHER
+// DataUpload/backup happened to be reconciling at the same moment. Passing
+// that unfiltered text straight to CheckIfFlakeOccurred lets a stale line
+// from a completely different, earlier spec's backup match a known-bug
+// pattern and misattribute it to the CURRENT spec -- confirmed as a real risk
+// live: the skip path this filtering protects deletes the current spec's own
+// backup via DeleteVeleroBackupAndRestore before skipping, so a
+// misattributed match could make an otherwise-healthy spec delete its own
+// good backup over noise from someone else's stuck one. Callers should pass
+// the specific backup name and/or DataUpload name they actually care about.
+func FilterLogLinesContaining(logs string, substrs ...string) string {
+	if len(substrs) == 0 {
+		return logs
+	}
+	var matched []string
+	for _, line := range strings.Split(logs, "\n") {
+		for _, s := range substrs {
+			if s != "" && strings.Contains(line, s) {
+				matched = append(matched, line)
+				break
+			}
+		}
+	}
+	return strings.Join(matched, "\n")
+}
+
 // CheckIfFlakeOccurred checks for known flake patterns in the provided logs (typically logs from the test ran).
 //
 // Parameters:
 //
 //	logs ([]string):    Logs to be examined for known flake patterns.
+//
+// Name-bearing status of each pattern below, for callers pre-filtering with
+// FilterLogLinesContaining (verified against kdm-controller source
+// migtools/kubevirt-datamover-controller@internal/controller/kubevirt_dataupload_controller.go,
+// 2026-08-29 -- re-check this if that file's logger plumbing changes):
+//   - CNV-85377 ("is being attached to VMI"): not found verbatim in
+//     kdm-controller source; if it ever surfaces there it would be via a VMB
+//     condition Reason/Message logged inline (e.g. "reason", cond.Reason) on
+//     kdm-controller's shared, context-injected logger -- also safe to scope
+//     by backup/DataUpload name. Otherwise it's virt-controller's own
+//     condition text, which reaches us only via Kubernetes Events, same as
+//     the #18957 pattern below.
+//   - kubevirt#18957 ("VMI backup status was lost"): virt-controller's own
+//     event text, never appears in any pod log -- callers must check this
+//     against Namespace Events (already namespace-scoped), never filtered
+//     pod logs, or it will never match.
+//   - external-snapshotter#876, velero#5856, OADP-5086: velero/snapshot-controller
+//     strings that never appear in kdm-controller's own log; irrelevant to
+//     scoping decisions made against kdm-controller pod logs specifically.
 func CheckIfFlakeOccurred(logs []string) bool {
 	flakePatterns := []FlakePattern{
 		{
@@ -55,6 +103,16 @@ func CheckIfFlakeOccurred(logs []string) bool {
 			Description:         "Startup probe timeout causing deployment readiness failure after restore",
 			StringSearchPattern: "deployment is not in a ready state",
 		},
+		{
+			Issue:               "https://redhat.atlassian.net/browse/CNV-85377",
+			Description:         "virt-controller's VirtualMachineBackup status can silently stop advancing after the underlying attach already succeeded: startBackup()'s attach branch (kubevirt/kubevirt pkg/storage/cbt/backup.go) returns without writing a status condition or requeuing, so recovery depends entirely on a VMI watch event that may never fire again -- also reported as https://redhat.atlassian.net/browse/CNV-89684",
+			StringSearchPattern: "is being attached to VMI",
+		},
+		{
+			Issue:               "https://github.com/kubevirt/kubevirt/pull/18957",
+			Description:         "virt-controller's reconcileStart() (pkg/storage/cbt/backup.go) can mark an already-successfully-completed VirtualMachineBackup Failed with reason SourceLost: cleanupVMIState() clears the VMI's BackupStatus and re-triggers reconcile before the backup's own just-written terminal status is visible via the informer's async cache, so the stale reconcile wrongly concludes the status was lost mid-flight -- observed live immediately after a real 'Completed VirtualMachineBackup, warning: ...' event, first seen testing kubevirt/kubevirt nightly (v1.20.0). Fixed at kubevirt/kubevirt#18957 (checks the API server directly before concluding lost); distinct from CNV-85377/kubevirt/kubevirt#18949.",
+			StringSearchPattern: "VMI backup status was lost",
+		},
 	}
 	logString := strings.Join(logs, "\n")
 

tests/e2e/lib/flakes_test.go

@@ -0,0 +1,70 @@
+package lib
+
+import (
+	"strings"
+	"testing"
+)
+
+// Real kdm-controller manager.log lines captured from a live CI run
+// (/tmp/kdm-mgr-log2.txt, 2026-08-28T16:48-16:49Z), covering two different
+// specs' DataUploads reconciling concurrently against the SAME shared,
+// never-restarted controller pod -- exactly the scenario
+// FilterLogLinesContaining exists to guard against.
+
+// du-cirros-incr-seq-1-... is the DataUpload for backup "cirros-incr-seq-1".
+// These two lines are real, unmodified captures of the #212 flake pattern
+// ("VMBT already prepared but VMB not yet visible in cache, requeuing").
+const realLine212A = `2026-08-28T16:48:47Z	INFO	VMBT already prepared but VMB not yet visible in cache, requeuing	{"controller": "kubevirt-dataupload", "controllerGroup": "velero.io", "controllerKind": "DataUpload", "DataUpload": {"name":"du-cirros-incr-seq-1-cirros-test-cirros-test-c2ce2dc4","namespace":"openshift-adp"}, "namespace": "openshift-adp", "name": "du-cirros-incr-seq-1-cirros-test-cirros-test-c2ce2dc4", "reconcileID": "fd536430-7cab-4758-813a-3aafd75e8934", "vmbtName": "vmbt-cirros-test-n58ss"}`
+const realLine212B = `2026-08-28T16:48:52Z	INFO	VMBT already prepared but VMB not yet visible in cache, requeuing	{"controller": "kubevirt-dataupload", "controllerGroup": "velero.io", "controllerKind": "DataUpload", "DataUpload": {"name":"du-cirros-incr-seq-1-cirros-test-cirros-test-c2ce2dc4","namespace":"openshift-adp"}, "namespace": "openshift-adp", "name": "du-cirros-incr-seq-1-cirros-test-cirros-test-c2ce2dc4", "reconcileID": "eef72d18-8408-4f90-8405-9be3972cad30", "vmbtName": "vmbt-cirros-test-n58ss"}`
+
+// du-cirros-stale-sibling-backup-... is a DIFFERENT spec's DataUpload,
+// reconciling in the same log window with no problems at all (healthy,
+// unrelated noise -- the real-world shape of what a whole-pod-log fetch
+// mixes in alongside the spec actually under test).
+const realLineHealthyA = `2026-08-28T16:49:21Z	INFO	Reconciling DataUpload with kubevirt datamover	{"controller": "kubevirt-dataupload", "controllerGroup": "velero.io", "controllerKind": "DataUpload", "DataUpload": {"name":"du-cirros-stale-sibling-backup-cirros-test-cirros-test-86ae9509","namespace":"openshift-adp"}, "namespace": "openshift-adp", "name": "du-cirros-stale-sibling-backup-cirros-test-cirros-test-86ae9509", "reconcileID": "aae0a708-caca-4e5e-9a4b-dd763622396a", "dataUpload": {"name":"du-cirros-stale-sibling-backup-cirros-test-cirros-test-86ae9509","namespace":"openshift-adp"}, "phase": ""}`
+const realLineHealthyB = `2026-08-28T16:49:21Z	INFO	Handling New phase DataUpload	{"controller": "kubevirt-dataupload", "controllerGroup": "velero.io", "controllerKind": "DataUpload", "DataUpload": {"name":"du-cirros-stale-sibling-backup-cirros-test-cirros-test-86ae9509","namespace":"openshift-adp"}, "namespace": "openshift-adp", "name": "du-cirros-stale-sibling-backup-cirros-test-cirros-test-86ae9509", "reconcileID": "aae0a708-caca-4e5e-9a4b-dd763622396a"}`
+const realLineHealthyC = `2026-08-28T16:49:21Z	INFO	Updated DataUpload phase	{"controller": "kubevirt-dataupload", "controllerGroup": "velero.io", "controllerKind": "DataUpload", "DataUpload": {"name":"du-cirros-stale-sibling-backup-cirros-test-cirros-test-86ae9509","namespace":"openshift-adp"}, "namespace": "openshift-adp", "name": "du-cirros-stale-sibling-backup-cirros-test-cirros-test-86ae9509", "reconcileID": "aae0a708-caca-4e5e-9a4b-dd763622396a", "dataUpload": "du-cirros-stale-sibling-backup-cirros-test-cirros-test-86ae9509", "phase": "Accepted", "message": "DataUpload accepted by kubevirt datamover"}`
+
+// The #208 pattern ("VirtualMachineBackup in progress, requeuing") and the
+// #212 pattern above were both removed from CheckIfFlakeOccurred once a kdm-controller
+// build carrying migtools/kubevirt-datamover-controller#208 and #212 was
+// verified live (2026-08-29, quay.io/tkaovila/kubevirt-datamover-controller:combined-208-212-test)
+// to produce a genuine PASS of the incremental-sequence spec with zero
+// occurrences of either pattern string, where it had previously reliably
+// flake-skipped within ~20 minutes. realLine212A/B stay as fixture data below
+// since they're still useful, realistic-shaped log content for exercising
+// FilterLogLinesContaining's own scoping logic -- they just no longer
+// exercise CheckIfFlakeOccurred's pattern registry.
+
+const backupName = "cirros-incr-seq-1"
+const dataUploadName = "du-cirros-incr-seq-1-cirros-test-cirros-test-c2ce2dc4"
+const staleSiblingBackupName = "cirros-stale-sibling-backup"
+const staleSiblingDataUploadName = "du-cirros-stale-sibling-backup-cirros-test-cirros-test-86ae9509"
+
+func combinedPodLog() string {
+	return strings.Join([]string{
+		realLineHealthyA,
+		realLineHealthyB,
+		realLine212A,
+		realLine212B,
+		realLineHealthyC,
+	}, "\n")
+}
+
+func Test_FilterLogLinesContaining_scopesToOwnBackup(t *testing.T) {
+	filtered := FilterLogLinesContaining(combinedPodLog(), backupName, dataUploadName)
+
+	if !strings.Contains(filtered, "VMBT already prepared but VMB not yet visible in cache, requeuing") {
+		t.Fatalf("expected filtered log to retain the #212 pattern line for %s, got:\n%s", backupName, filtered)
+	}
+	if strings.Contains(filtered, staleSiblingDataUploadName) {
+		t.Fatalf("expected filtered log to exclude the unrelated sibling backup's lines, got:\n%s", filtered)
+	}
+}
+
+func Test_FilterLogLinesContaining_noSubstrsReturnsInputUnchanged(t *testing.T) {
+	logs := combinedPodLog()
+	if got := FilterLogLinesContaining(logs); got != logs {
+		t.Fatalf("expected unfiltered passthrough with no substrs, got:\n%s", got)
+	}
+}