Bug 2005347

4.8's WaitForStableCluster [1].  Looks like it includes "Timed out waiting for the following pods to schedule..." in test-case stdout, but sadly does not include that information in the framework.Failf message.  Seems like a useful upstream fix to try to at least sketch the unscheduled pause in the failure message.

But popping open stdout for one of these failing test cases in comment 0's job:

Sep 17 09:40:52.454: INFO: Timed out waiting for the following pods to schedule
Sep 17 09:40:52.454: INFO: openshift-authentication/oauth-openshift-684f7bffb-tcdfv
Sep 17 09:40:52.455: FAIL: Timed out after 10m0s waiting for stable cluster.

And dropping into gathered assets:

$ curl -s https://gcsweb-ci.apps.ci.l2s4.p1.openshiftapps.com/gcs/origin-ci-test/logs/periodic-ci-openshift-release-master-nightly-4.8-e2e-aws-canary/1438781824678498304/artifacts/e2e-aws-canary/gather-extra/artifacts/pods.json | jq '.items[] | select(.metadata.name == "oauth-openshift-684f7bffb-tcdfv").status'
{
  "conditions": [
    {
      "lastProbeTime": null,
      "lastTransitionTime": "2021-09-17T08:49:30Z",
      "message": "0/6 nodes are available: 3 node(s) didn't match Pod's node affinity/selector, 3 node(s) didn't match pod affinity/anti-affinity rules, 3 node(s) didn't match pod anti-affinity rules.",
      "reason": "Unschedulable",
      "status": "False",
      "type": "PodScheduled"
    }
  ],
  "phase": "Pending",
  "qosClass": "Burstable"
}

So did we break anti-affinity?  Or the auth pods are being misconfigured?

$ curl -s https://gcsweb-ci.apps.ci.l2s4.p1.openshiftapps.com/gcs/origin-ci-test/logs/periodic-ci-openshift-release-master-nightly-4.8-e2e-aws-canary/1438781824678498304/artifacts/e2e-aws-canary/gather-extra/artifacts/pods.json | jq '.items[] | select(.metadata.name == "oauth-openshift-684f7bffb-tcdfv").spec.affinity'
{
  "podAntiAffinity": {
    "requiredDuringSchedulingIgnoredDuringExecution": [
      {
        "labelSelector": {
          "matchLabels": {
            "app": "oauth-openshift",
            "oauth-openshift-anti-affinity": "true"
          }
        },
        "topologyKey": "kubernetes.io/hostname"
      }
    ]
  }
}

[1]: https://github.com/openshift/origin/blob/a7992c389e048b27a3dfb1a05e9d2691f9e8f371/vendor/k8s.io/kubernetes/test/e2e/scheduling/framework.go#L43-L61

Or maybe we're trying (and failing) to surge with three replicas?  And the surging fourth pod has no fourth node to live on.

$ curl -s https://gcsweb-ci.apps.ci.l2s4.p1.openshiftapps.com/gcs/origin-ci-test/logs/periodic-ci-openshift-release-master-nightly-4.8-e2e-aws-canary/1438781824678498304/artifacts/e2e-aws-canary/gather-extra/artifacts/pods.json | jq -r '.items[].metadata.name | select(startswith("oauth-openshift-"))'
oauth-openshift-5ccc6f4c65-qg6jb
oauth-openshift-5ccc6f4c65-qvd8h
oauth-openshift-684f7bffb-pgcnx
oauth-openshift-684f7bffb-tcdfv

$ curl -s https://gcsweb-ci.apps.ci.l2s4.p1.openshiftapps.com/gcs/origin-ci-test/logs/periodic-ci-openshift-release-master-nightly-4.8-e2e-aws-canary/1438781824678498304/artifacts/e2e-aws-canary/gather-extra/artifacts/deployments.json | jq '.items[] | select(.metadata.name == "oauth-openshift").spec | {replicas, strategy}'
{
  "replicas": 3,
  "strategy": {
    "rollingUpdate": {
      "maxSurge": 0,
      "maxUnavailable": 1
    },
    "type": "RollingUpdate"
  }
}

So not surging...  Aha:

$ curl -s https://gcsweb-ci.apps.ci.l2s4.p1.openshiftapps.com/gcs/origin-ci-test/logs/periodic-ci-openshift-release-master-nightly-4.8-e2e-aws-canary/1438781824678498304/artifacts/e2e-aws-canary/gather-extra/artifacts/pods.json | jq -r '.items[] | select((.metadata.name | startswith("oauth-openshift-")) and .status.phase == "Pending").metadata | keys'
[
  "annotations",
  "creationTimestamp",
  "deletionGracePeriodSeconds",
  "deletionTimestamp",
  "generateName",
  "labels",
  "name",
  "namespace",
  "ownerReferences",
  "resourceVersion",
  "uid"
]
[
  "annotations",
  "creationTimestamp",
  "generateName",
  "labels",
  "name",
  "namespace",
  "ownerReferences",
  "resourceVersion",
  "uid"
]

So I bet this is a symptom of bug 1952224, and can be closed as a dup (possibly with Sippy metadata sync'ed over?).  The issue is that a sibling pod hit bug 1952224 and hung in termination, and then anti-affinity locked scheduling a new sibling, and then WaitForStableCluster locked on the unscheduled sibling.

Or maybe we keep this bug open, and use it to track including a summary of unscheduled pods in WaitForStableCluster's framework.Failf?

I prefer to have an issue against a specific issue which we can debug and fix. It takes longer to collect what is wrong from the kubelet and the scheduler logs. Though, it's still doable.

*** This bug has been marked as a duplicate of bug 1952224 ***