kubernetes: Inconsistent Job state on DeadlineExceeded

What happened?

We have a maintenance task running in our clusters to delete obsolete jobs. The task uses a field selector to list completed jobs, status.successful=1, and then uses the .status.completionTime field to decide if the job should be deleted. This has been running fine for a long time, but suddenly the task started crashing in one of our clusters. After some initial investigation it turns out that this is caused by .status.completionTime being unset, even if the job appeared to have been completed successfully, based on status.successful/status.succeeded.

After removing irrelevant fields, the job may look like this:

apiVersion: batch/v1
kind: Job
spec:
  activeDeadlineSeconds: 220
  backoffLimit: 7
  completionMode: NonIndexed
  completions: 1
  parallelism: 1
status:
  conditions:
  - lastProbeTime: "2023-04-12T09:16:57Z"
    lastTransitionTime: "2023-04-12T09:16:57Z"
    message: Job was active longer than specified deadline
    reason: DeadlineExceeded
    status: "True"
    type: Failed
  ready: 0
  startTime: "2023-04-12T08:24:47Z"
  succeeded: 1

Which I find quite inconsistent. Has the job completed successfully or did it fail?

What did you expect to happen?

I would expect a consistent state based on the job pod status, and it seems like the correct state for these jobs is Failed - since the deadline exceeded before the pod containers were allowed to finish normally with exit code 0. So I would expect .status.succeeded to be unset (0) and .status.failed to be 1.

How can we reproduce it (as minimally and precisely as possible)?

We have tried to reproduce this problem without success. I suspect the root cause to be the cluster job-controller being overwhelmed with work - caused by some unfortunate user cronjobs defined in a “playground” namespace. We got reports of long delays in job pod creation (over 1 hour) when this was going on. After some investigation, we decided to delete the problematic cronjobs (including the owned jobs), and this seems to have resolved the issue. And I have yet to see any new jobs in the inconsistent state after this action.

Anything else we need to know?

It seems to me like the job pod is created just before the activation deadline when this happens. This causes the pod to be terminated before it is able to complete (or even startup). Here is a full example of a problematic job and pod, where I removed managed fields and redacted a couple of (hopefully irrelevant) fields:

kind: Job
apiVersion: batch/v1
metadata:
  resourceVersion: '2403235324'
  name: bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cabd44e
  uid: 4cdd8e07-2299-4ab1-bd18-86b71cd76daa
  creationTimestamp: '2023-04-12T07:57:18Z'
  generation: 1
  namespace: openshift-marketplace
  ownerReferences:
    - apiVersion: v1
      kind: ConfigMap
      name: bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cabd44e
      uid: 86b58401-e302-4542-9a34-a913b486081e
      controller: false
      blockOwnerDeletion: false
  labels:
    controller-uid: 4cdd8e07-2299-4ab1-bd18-86b71cd76daa
    job-name: bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cabd44e
spec:
  parallelism: 1
  completions: 1
  activeDeadlineSeconds: 600
  backoffLimit: 3
  selector:
    matchLabels:
      controller-uid: 4cdd8e07-2299-4ab1-bd18-86b71cd76daa
  template:
    metadata:
      name: bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cabd44e
      creationTimestamp: null
      labels:
        controller-uid: 4cdd8e07-2299-4ab1-bd18-86b71cd76daa
        job-name: bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cabd44e
    spec:
      volumes:
        - name: bundle
          emptyDir: {}
        - name: util
          emptyDir: {}
      initContainers:
        - name: util
          image: >-
            quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:c8457e6399df19fbc84154e13c18b72c8c79d92aedc9f84a03032429117f64f7
          command:
            - /bin/cp
            - '-Rv'
            - /bin/cpb
            - /util/cpb
          resources:
            requests:
              cpu: 10m
              memory: 50Mi
          volumeMounts:
            - name: util
              mountPath: /util
          terminationMessagePath: /dev/termination-log
          terminationMessagePolicy: File
          imagePullPolicy: IfNotPresent
        - name: pull
          image: >-
            registry.redhat.io/openshift4/ose-vertical-pod-autoscaler-operator-bundle@sha256:110faebb96e49bb69a5f9fe80eabf2fee7c16e1a99d90b5707c6098977fb87fa
          command:
            - /util/cpb
            - /bundle
          resources:
            requests:
              cpu: 10m
              memory: 50Mi
          volumeMounts:
            - name: bundle
              mountPath: /bundle
            - name: util
              mountPath: /util
          terminationMessagePath: /dev/termination-log
          terminationMessagePolicy: File
          imagePullPolicy: Always
      containers:
        - resources:
            requests:
              cpu: 10m
              memory: 50Mi
          terminationMessagePath: /dev/termination-log
          name: extract
          command:
            - opm
            - alpha
            - bundle
            - extract
            - '-m'
            - /bundle/
            - '-n'
            - openshift-marketplace
            - '-c'
            - bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cabd44e
            - '-z'
          env:
            - name: CONTAINER_IMAGE
              value: >-
                registry.redhat.io/openshift4/ose-vertical-pod-autoscaler-operator-bundle@sha256:110faebb96e49bb69a5f9fe80eabf2fee7c16e1a99d90b5707c6098977fb87fa
          imagePullPolicy: IfNotPresent
          volumeMounts:
            - name: bundle
              mountPath: /bundle
          terminationMessagePolicy: File
          image: >-
            quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:6dd7def332bc744a37117062338d611489e31e7db532ee5d1ea8f7fe6dd4854f
      restartPolicy: Never
      terminationGracePeriodSeconds: 30
      dnsPolicy: ClusterFirst
      securityContext: {}
      schedulerName: default-scheduler
  completionMode: NonIndexed
  suspend: false
status:
  conditions:
    - type: Failed
      status: 'True'
      lastProbeTime: '2023-04-12T09:42:36Z'
      lastTransitionTime: '2023-04-12T09:42:36Z'
      reason: DeadlineExceeded
      message: Job was active longer than specified deadline
  startTime: '2023-04-12T08:49:11Z'
  succeeded: 1
  ready: 0

kind: Pod
apiVersion: v1
metadata:
  generateName: bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cabd44e-
  annotations:
    k8s.v1.cni.cncf.io/network-status: |-
      [{
          "name": "openshift-sdn",
          "interface": "eth0",
          "ips": [
              "10.101.12.229"
          ],
          "default": true,
          "dns": {}
      }]
    k8s.v1.cni.cncf.io/networks-status: |-
      [{
          "name": "openshift-sdn",
          "interface": "eth0",
          "ips": [
              "10.101.12.229"
          ],
          "default": true,
          "dns": {}
      }]
    openshift.io/scc: restricted-v2
    seccomp.security.alpha.kubernetes.io/pod: runtime/default
  resourceVersion: '2403089947'
  name: bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cafh6t2
  uid: 9d862daa-30dd-4b09-9897-b9137291c1f6
  creationTimestamp: '2023-04-12T08:49:11Z'
  namespace: openshift-marketplace
  ownerReferences:
    - apiVersion: batch/v1
      kind: Job
      name: bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cabd44e
      uid: 4cdd8e07-2299-4ab1-bd18-86b71cd76daa
      controller: true
      blockOwnerDeletion: true
  labels:
    controller-uid: 4cdd8e07-2299-4ab1-bd18-86b71cd76daa
    job-name: bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cabd44e
spec:
  restartPolicy: Never
  initContainers:
    - resources:
        requests:
          cpu: 10m
          memory: 50Mi
      terminationMessagePath: /dev/termination-log
      name: util
      command:
        - /bin/cp
        - '-Rv'
        - /bin/cpb
        - /util/cpb
      securityContext:
        capabilities:
          drop:
            - ALL
        runAsUser: 1000220000
        runAsNonRoot: true
      imagePullPolicy: IfNotPresent
      volumeMounts:
        - name: util
          mountPath: /util
        - name: kube-api-access-nlbdk
          readOnly: true
          mountPath: /var/run/secrets/kubernetes.io/serviceaccount
      terminationMessagePolicy: File
      image: >-
        quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:c8457e6399df19fbc84154e13c18b72c8c79d92aedc9f84a03032429117f64f7
    - resources:
        requests:
          cpu: 10m
          memory: 50Mi
      terminationMessagePath: /dev/termination-log
      name: pull
      command:
        - /util/cpb
        - /bundle
      securityContext:
        capabilities:
          drop:
            - ALL
        runAsUser: 1000220000
        runAsNonRoot: true
      imagePullPolicy: Always
      volumeMounts:
        - name: bundle
          mountPath: /bundle
        - name: util
          mountPath: /util
        - name: kube-api-access-nlbdk
          readOnly: true
          mountPath: /var/run/secrets/kubernetes.io/serviceaccount
      terminationMessagePolicy: File
      image: >-
        registry.redhat.io/openshift4/ose-vertical-pod-autoscaler-operator-bundle@sha256:110faebb96e49bb69a5f9fe80eabf2fee7c16e1a99d90b5707c6098977fb87fa
  serviceAccountName: default
  imagePullSecrets:
    - name: default-dockercfg-dldx6
  priority: 0
  schedulerName: default-scheduler
  enableServiceLinks: true
  terminationGracePeriodSeconds: 30
  preemptionPolicy: PreemptLowerPriority
  nodeName: <REDACTED>
  securityContext:
    seLinuxOptions:
      level: 's0:c15,c5'
    fsGroup: 1000220000
    seccompProfile:
      type: RuntimeDefault
  containers:
    - resources:
        requests:
          cpu: 10m
          memory: 50Mi
      terminationMessagePath: /dev/termination-log
      name: extract
      command:
        - opm
        - alpha
        - bundle
        - extract
        - '-m'
        - /bundle/
        - '-n'
        - openshift-marketplace
        - '-c'
        - bcd7617aa4a4683952afb2568984d1b5396fef9eee92589166e822a9cabd44e
        - '-z'
      env:
        - name: CONTAINER_IMAGE
          value: >-
            registry.redhat.io/openshift4/ose-vertical-pod-autoscaler-operator-bundle@sha256:110faebb96e49bb69a5f9fe80eabf2fee7c16e1a99d90b5707c6098977fb87fa
      securityContext:
        capabilities:
          drop:
            - ALL
        runAsUser: 1000220000
        runAsNonRoot: true
      imagePullPolicy: IfNotPresent
      volumeMounts:
        - name: bundle
          mountPath: /bundle
        - name: kube-api-access-nlbdk
          readOnly: true
          mountPath: /var/run/secrets/kubernetes.io/serviceaccount
      terminationMessagePolicy: File
      image: >-
        quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:6dd7def332bc744a37117062338d611489e31e7db532ee5d1ea8f7fe6dd4854f
  serviceAccount: default
  volumes:
    - name: bundle
      emptyDir: {}
    - name: util
      emptyDir: {}
    - name: kube-api-access-nlbdk
      projected:
        sources:
          - serviceAccountToken:
              expirationSeconds: 3607
              path: token
          - configMap:
              name: kube-root-ca.crt
              items:
                - key: ca.crt
                  path: ca.crt
          - downwardAPI:
              items:
                - path: namespace
                  fieldRef:
                    apiVersion: v1
                    fieldPath: metadata.namespace
          - configMap:
              name: openshift-service-ca.crt
              items:
                - key: service-ca.crt
                  path: service-ca.crt
        defaultMode: 420
  dnsPolicy: ClusterFirst
  tolerations:
    - key: node.kubernetes.io/not-ready
      operator: Exists
      effect: NoExecute
      tolerationSeconds: 300
    - key: node.kubernetes.io/unreachable
      operator: Exists
      effect: NoExecute
      tolerationSeconds: 300
    - key: node.kubernetes.io/memory-pressure
      operator: Exists
      effect: NoSchedule
status:
  containerStatuses:
    - restartCount: 0
      started: false
      ready: false
      name: extract
      state:
        terminated:
          exitCode: 0
          reason: Completed
          startedAt: '2023-04-12T08:49:23Z'
          finishedAt: '2023-04-12T08:49:23Z'
          containerID: >-
            cri-o://d9c1281a2bf4370c9827f927a17f6792539a172e3260b17743574e2612b6bddc
      imageID: >-
        quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:6dd7def332bc744a37117062338d611489e31e7db532ee5d1ea8f7fe6dd4854f
      image: >-
        quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:6dd7def332bc744a37117062338d611489e31e7db532ee5d1ea8f7fe6dd4854f
      lastState: {}
      containerID: 'cri-o://d9c1281a2bf4370c9827f927a17f6792539a172e3260b17743574e2612b6bddc'
  qosClass: Burstable
  podIPs:
    - ip: 10.101.12.229
  podIP: 10.101.12.229
  hostIP: <REDACTED>
  startTime: '2023-04-12T08:49:11Z'
  initContainerStatuses:
    - name: util
      state:
        terminated:
          exitCode: 0
          reason: Completed
          startedAt: '2023-04-12T08:49:13Z'
          finishedAt: '2023-04-12T08:49:13Z'
          containerID: >-
            cri-o://19438fe7a2e5bf158cd2f348e47d729585b61e262c6348f94ad0ad4fe1b5eeb4
      lastState: {}
      ready: true
      restartCount: 0
      image: >-
        quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:c8457e6399df19fbc84154e13c18b72c8c79d92aedc9f84a03032429117f64f7
      imageID: >-
        quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:c8457e6399df19fbc84154e13c18b72c8c79d92aedc9f84a03032429117f64f7
      containerID: 'cri-o://19438fe7a2e5bf158cd2f348e47d729585b61e262c6348f94ad0ad4fe1b5eeb4'
    - name: pull
      state:
        terminated:
          exitCode: 0
          reason: Completed
          startedAt: '2023-04-12T08:49:14Z'
          finishedAt: '2023-04-12T08:49:14Z'
          containerID: >-
            cri-o://23a66dcaeb21c981ab795125196b3328acbece1e63e0fdf35354c8da9693552c
      lastState: {}
      ready: true
      restartCount: 0
      image: >-
        registry.redhat.io/openshift4/ose-vertical-pod-autoscaler-operator-bundle@sha256:110faebb96e49bb69a5f9fe80eabf2fee7c16e1a99d90b5707c6098977fb87fa
      imageID: >-
        registry.redhat.io/openshift4/ose-vertical-pod-autoscaler-operator-bundle@sha256:110faebb96e49bb69a5f9fe80eabf2fee7c16e1a99d90b5707c6098977fb87fa
      containerID: 'cri-o://23a66dcaeb21c981ab795125196b3328acbece1e63e0fdf35354c8da9693552c'
  conditions:
    - type: Initialized
      status: 'True'
      lastProbeTime: null
      lastTransitionTime: '2023-04-12T08:49:15Z'
      reason: PodCompleted
    - type: Ready
      status: 'False'
      lastProbeTime: null
      lastTransitionTime: '2023-04-12T08:49:11Z'
      reason: PodCompleted
    - type: ContainersReady
      status: 'False'
      lastProbeTime: null
      lastTransitionTime: '2023-04-12T08:49:11Z'
      reason: PodCompleted
    - type: PodScheduled
      status: 'True'
      lastProbeTime: null
      lastTransitionTime: '2023-04-12T08:49:11Z'
  phase: Succeeded

Kubernetes version

$ kubectl version
WARNING: This version information is deprecated and will be replaced with the output from kubectl version --short.  Use --output=yaml|json to get the full version.
Client Version: version.Info{Major:"1", Minor:"24", GitVersion:"v1.24.1", GitCommit:"142cb4431e96f510b4ed4c61a13d68cb13a76c3c", GitTreeState:"clean", BuildDate:"2022-11-07T22:44:06Z", GoVersion:"go1.18.7", Compiler:"gc", Platform:"linux/amd64"}
Kustomize Version: v4.5.4
Server Version: version.Info{Major:"1", Minor:"24", GitVersion:"v1.24.11+af0420d", GitCommit:"4d360c68d64c7884b93c22a21a02085bee8c12b7", GitTreeState:"clean", BuildDate:"2023-03-14T11:40:32Z", GoVersion:"go1.18.7", Compiler:"gc", Platform:"linux/amd64"}

Cloud provider

OS version

# On Linux:
$ cat /etc/os-release
# paste output here
$ uname -a
# paste output here

# On Windows:
C:\> wmic os get Caption, Version, BuildNumber, OSArchitecture
# paste output here

Install tools

Container runtime (CRI) and version (if applicable)

Related plugins (CNI, CSI, …) and versions (if applicable)