Karpenter disrupting pods with `karpenter.sh/do-not-disrupt: "true"` annotation

[AleksaC]

Description

Observed Behavior:

Karpenter provisioned a node (ip-10-3-166-58.eu-central-1.compute.internal) to schedule two pending pods (runner-6fvcfnjvw-project-335-concurrent-0-jnhl2u9b and runner-6fvcfnjvw-project-335-concurrent-1-1zfg6jd5) only to consolidate the node and evict the pods ~20s later. The pods were annotated with karpenter.sh/do-not-disrupt: "true".

Here are excerpts from karpenter logs and k8s events.

2024-03-05 10:29:54	 {"level":"INFO","time":"2024-03-05T09:29:54.109Z","logger":"controller.nodeclaim.lifecycle","message":"initialized nodeclaim","commit":"596ea97","nodeclaim":"gitlab-runner-overflow-sbdgm","provider-id":"aws:///eu-central-1b/i-026f428dc48c7d1e1","node":"ip-10-3-166-58.eu-central-1.compute.internal"}
2024-03-05 10:30:14	 {"level":"INFO","time":"2024-03-05T09:30:14.357Z","logger":"controller.disruption","message":"disrupting via consolidation delete, terminating 1 candidates ip-10-3-166-58.eu-central-1.compute.internal/t3.large/spot","commit":"596ea97","command-id":"296e8d57-8002-4e62-99fe-951d4bd3bb77"}
2024-03-05 10:30:14	 {"level":"INFO","time":"2024-03-05T09:30:14.823Z","logger":"controller.disruption.queue","message":"command succeeded","commit":"596ea97","command-id":"296e8d57-8002-4e62-99fe-951d4bd3bb77"}
2024-03-05 10:30:14	 {"level":"INFO","time":"2024-03-05T09:30:14.869Z","logger":"controller.node.termination","message":"tainted node","commit":"596ea97","node":"ip-10-3-166-58.eu-central-1.compute.internal"}
2024-03-05 10:30:16	 {"level":"INFO","time":"2024-03-05T09:30:16.489Z","logger":"controller.node.termination","message":"deleted node","commit":"596ea97","node":"ip-10-3-166-58.eu-central-1.compute.internal"}
2024-03-05 10:30:16	 {"level":"INFO","time":"2024-03-05T09:30:16.812Z","logger":"controller.nodeclaim.termination","message":"deleted nodeclaim","commit":"596ea97","nodeclaim":"gitlab-runner-overflow-sbdgm","node":"ip-10-3-166-58.eu-central-1.compute.internal","provider-id":"aws:///eu-central-1b/i-026f428dc48c7d1e1"}

45m         Normal    Scheduled              pod/runner-6fvcfnjvw-project-335-concurrent-0-jnhl2u9b   Successfully assigned gitlab-runner/runner-6fvcfnjvw-project-335-concurrent-0-jnhl2u9b to ip-10-3-166-58.eu-central-1.compute.internal
45m         Normal    Pulling                pod/runner-6fvcfnjvw-project-335-concurrent-0-jnhl2u9b   Pulling image "registry.gitlab.com/gitlab-org/gitlab-runner/gitlab-runner-helper:x86_64-f5da3c5a"
45m         Normal    Created                pod/runner-6fvcfnjvw-project-335-concurrent-0-jnhl2u9b   Created container init-permissions
45m         Normal    Pulled                 pod/runner-6fvcfnjvw-project-335-concurrent-0-jnhl2u9b   Successfully pulled image "registry.gitlab.com/gitlab-org/gitlab-runner/gitlab-runner-helper:x86_64-f5da3c5a" in 4.204s (4.204s including waiting)
45m         Normal    Started                pod/runner-6fvcfnjvw-project-335-concurrent-0-jnhl2u9b   Started container init-permissions
45m         Normal    Pulling                pod/runner-6fvcfnjvw-project-335-concurrent-0-jnhl2u9b   Pulling image "node:18-alpine"
45m         Normal    Evicted                pod/runner-6fvcfnjvw-project-335-concurrent-0-jnhl2u9b   Evicted pod

45m         Normal    Scheduled              pod/runner-6fvcfnjvw-project-335-concurrent-1-1zfg6jd5   Successfully assigned gitlab-runner/runner-6fvcfnjvw-project-335-concurrent-1-1zfg6jd5 to ip-10-3-166-58.eu-central-1.compute.internal
45m         Normal    Pulling                pod/runner-6fvcfnjvw-project-335-concurrent-1-1zfg6jd5   Pulling image "registry.gitlab.com/gitlab-org/gitlab-runner/gitlab-runner-helper:x86_64-f5da3c5a"
45m         Normal    Pulled                 pod/runner-6fvcfnjvw-project-335-concurrent-1-1zfg6jd5   Successfully pulled image "registry.gitlab.com/gitlab-org/gitlab-runner/gitlab-runner-helper:x86_64-f5da3c5a" in 3.579s (3.579s including waiting)
45m         Normal    Created                pod/runner-6fvcfnjvw-project-335-concurrent-1-1zfg6jd5   Created container init-permissions
45m         Normal    Started                pod/runner-6fvcfnjvw-project-335-concurrent-1-1zfg6jd5   Started container init-permissions
45m         Normal    Pulling                pod/runner-6fvcfnjvw-project-335-concurrent-1-1zfg6jd5   Pulling image "node:18-alpine"
45m         Normal    Evicted                pod/runner-6fvcfnjvw-project-335-concurrent-1-1zfg6jd5   Evicted pod

The two pods were the only thing scheduled on the node other than daemonsets.

I have no reason to believe that the pods got evicted by some other process and karpenter just cleaned up the node afterwards. Because prometheus only got a single scrape of the node metrics I cannot guarantee that there was no node pressure based on that, but it's very unlikely since the pods that were scheduled on the node consume next to no resources and the timespan was very short.

Expected Behavior:

Reproduction Steps (Please include YAML):

I cannot really provide a set of manifests that would reproduce this deterministically as it's the first time this happened in a couple of weeks that this setup has been active.

Here is the NodePool manifest if it helps with anything:

apiVersion: karpenter.sh/v1beta1
kind: NodePool
metadata:
  annotations:
    meta.helm.sh/release-name: gitlab-runner
    meta.helm.sh/release-namespace: gitlab-runner
  labels:
    app.kubernetes.io/managed-by: Helm
  name: gitlab-runner-overflow
spec:
  disruption:
    budgets:
    - nodes: 10%
    consolidationPolicy: WhenUnderutilized
    expireAfter: Never
  limits:
    cpu: "12"
  template:
    spec:
      nodeClassRef:
        name: default
      requirements:
      - key: karpenter.sh/capacity-type
        operator: In
        values:
        - spot
        - on-demand
      - key: kubernetes.io/arch
        operator: In
        values:
        - amd64
      - key: karpenter.k8s.aws/instance-family
        operator: In
        values:
        - t3
      - key: karpenter.k8s.aws/instance-size
        operator: In
        values:
        - medium
        - large
        - xlarge
      - key: kubernetes.io/os
        operator: In
        values:
        - linux
      taints:
      - effect: NoSchedule
        key: gitlab-runner
  weight: 98

It would be helpful if karpenter provided more information in its logs. I glanced at the code to see if maybe there is more useful info if I changed the log level to debug, but couldn't find anything to support that.

Versions:

• Chart Version: v0.34.1
• Kubernetes Version (kubectl version): 1.28

---

• Please vote on this issue by adding a 👍 reaction to the original issue to help the community and maintainers prioritize this request
• Please do not leave "+1" or "me too" comments, they generate extra noise for issue followers and do not help prioritize the request
• If you are interested in working on this issue or have submitted a pull request, please leave a comment

[engedaam]

Do you know if the pods ever entered into a running state?

[AleksaC]

Based on the events above only the init-permissions init container started. I'm not sure if that counts as running or is it still waiting state.

I also checked kube_pod_status_phase KSM metric but there are no samples for the two pods, probably because their lifetime was shorter than the scrape interval.

[engedaam]

@AleksaC Can you share the pods spec?

[AleksaC]

apiVersion: v1
kind: Pod
metadata:
  annotations:
    karpenter.sh/do-not-disrupt: "true"
  labels:
    pod: runner-6fvcfnjvw-project-335-concurrent-0
  name: runner-6fvcfnjvw-project-335-concurrent-0-tufgrs7o
  namespace: gitlab-runner
spec:
  activeDeadlineSeconds: 3601
  affinity: {}
  containers:
  - command:
    - sh
    - -c
    - "if [ -x /usr/local/bin/bash ]; then\n\texec /usr/local/bin/bash \nelif [ -x
      /usr/bin/bash ]; then\n\texec /usr/bin/bash \nelif [ -x /bin/bash ]; then\n\texec
      /bin/bash \nelif [ -x /usr/local/bin/sh ]; then\n\texec /usr/local/bin/sh \nelif
      [ -x /usr/bin/sh ]; then\n\texec /usr/bin/sh \nelif [ -x /bin/sh ]; then\n\texec
      /bin/sh \nelif [ -x /busybox/sh ]; then\n\texec /busybox/sh \nelse\n\techo shell
      not found\n\texit 1\nfi\n\n"
    image: node:18-alpine
    imagePullPolicy: IfNotPresent
    name: build
    resources:
      limits:
        memory: 3Gi
      requests:
        cpu: 250m
        memory: 3Gi
    securityContext:
      capabilities:
        drop:
        - NET_RAW
    stdin: true
    terminationMessagePath: /dev/termination-log
    terminationMessagePolicy: File
    volumeMounts:
    - mountPath: /scripts-335-102274
      name: scripts
    - mountPath: /logs-335-102274
      name: logs
    - mountPath: /builds
      name: repo
    - mountPath: /var/run/secrets/kubernetes.io/serviceaccount
      name: kube-api-access-lv878
      readOnly: true
    - mountPath: /var/run/secrets/eks.amazonaws.com/serviceaccount
      name: aws-iam-token
      readOnly: true
  - command:
    - sh
    - -c
    - "if [ -x /usr/local/bin/bash ]; then\n\texec /usr/local/bin/bash \nelif [ -x
      /usr/bin/bash ]; then\n\texec /usr/bin/bash \nelif [ -x /bin/bash ]; then\n\texec
      /bin/bash \nelif [ -x /usr/local/bin/sh ]; then\n\texec /usr/local/bin/sh \nelif
      [ -x /usr/bin/sh ]; then\n\texec /usr/bin/sh \nelif [ -x /bin/sh ]; then\n\texec
      /bin/sh \nelif [ -x /busybox/sh ]; then\n\texec /busybox/sh \nelse\n\techo shell
      not found\n\texit 1\nfi\n\n"
    image: registry.gitlab.com/gitlab-org/gitlab-runner/gitlab-runner-helper:x86_64-f5da3c5a
    imagePullPolicy: IfNotPresent
    name: helper
    resources:
      limits:
        memory: 512Mi
      requests:
        cpu: 100m
        memory: 128Mi
    securityContext:
      capabilities:
        drop:
        - NET_RAW
    stdin: true
    terminationMessagePath: /dev/termination-log
    terminationMessagePolicy: File
    volumeMounts:
    - mountPath: /scripts-335-102274
      name: scripts
    - mountPath: /logs-335-102274
      name: logs
    - mountPath: /builds
      name: repo
    - mountPath: /var/run/secrets/kubernetes.io/serviceaccount
      name: kube-api-access-lv878
      readOnly: true
    - mountPath: /var/run/secrets/eks.amazonaws.com/serviceaccount
      name: aws-iam-token
      readOnly: true
  dnsPolicy: ClusterFirst
  enableServiceLinks: true
  imagePullSecrets:
  - name: runner-6fvcfnjvw-project-335-concurrent-0-v3o8xgoq
  initContainers:
  - command:
    - sh
    - -c
    - touch /logs-335-102274/output.log && (chmod 777 /logs-335-102274/output.log
      || exit 0)
    image: registry.gitlab.com/gitlab-org/gitlab-runner/gitlab-runner-helper:x86_64-f5da3c5a
    imagePullPolicy: IfNotPresent
    name: init-permissions
    resources:
      limits:
        memory: 512Mi
      requests:
        cpu: 100m
        memory: 128Mi
    securityContext:
      capabilities:
        drop:
        - NET_RAW
    terminationMessagePath: /dev/termination-log
    terminationMessagePolicy: File
    volumeMounts:
    - mountPath: /scripts-335-102274
      name: scripts
    - mountPath: /logs-335-102274
      name: logs
    - mountPath: /builds
      name: repo
    - mountPath: /var/run/secrets/kubernetes.io/serviceaccount
      name: kube-api-access-lv878
      readOnly: true
    - mountPath: /var/run/secrets/eks.amazonaws.com/serviceaccount
      name: aws-iam-token
      readOnly: true
  preemptionPolicy: PreemptLowerPriority
  priority: 0
  restartPolicy: Never
  schedulerName: default-scheduler
  securityContext: {}
  serviceAccount: gitlab-runner
  serviceAccountName: gitlab-runner
  terminationGracePeriodSeconds: 0
  tolerations:
  - effect: NoSchedule
    key: gitlab-runner
    operator: Exists
  - effect: NoExecute
    key: node.kubernetes.io/not-ready
    operator: Exists
    tolerationSeconds: 300
  - effect: NoExecute
    key: node.kubernetes.io/unreachable
    operator: Exists
    tolerationSeconds: 300
  volumes:
  - name: aws-iam-token
    projected:
      defaultMode: 420
      sources:
      - serviceAccountToken:
          audience: sts.amazonaws.com
          expirationSeconds: 86400
          path: token
  - emptyDir: {}
    name: repo
  - emptyDir: {}
    name: scripts
  - emptyDir: {}
    name: logs
  - name: kube-api-access-lv878
    projected:
      defaultMode: 420
      sources:
      - serviceAccountToken:
          expirationSeconds: 3607
          path: token
      - configMap:
          items:
          - key: ca.crt
            path: ca.crt
          name: kube-root-ca.crt
      - downwardAPI:
          items:
          - fieldRef:
              apiVersion: v1
              fieldPath: metadata.namespace
            path: namespace

[engedaam]

Based on the events above only the init-permissions init container started. I'm not sure if that counts as running or is it still waiting state.

From doing a little bit of research, I found that for a pod to be in a running state on a cluster the init container must have fully succeed https://devopscube.com/kubernetes-pod-lifecycle/. Is it possible that the init-container failed? If the init-container fails, then the whole pod will enter into a failed state when the restartPolicy: Never https://kubernetes.io/docs/concepts/workloads/pods/init-containers/#understanding-init-containers. Therefore, Karpenter will consider that node to be empty.

[AleksaC]

There were no indications that it failed in this case and AFAIK it never failed in thousands of executions.

Here's the init container snippet from the pod spec above:

  initContainers:
  - command:
    - sh
    - -c
    - touch /logs-335-102274/output.log && (chmod 777 /logs-335-102274/output.log || exit 0)
    name: init-permissions
    volumeMounts:
    - mountPath: /logs-335-102274
      name: logs
  volumes:
  - emptyDir: {}
    name: logs

touch could get a permission error but I'd see that in the logs. Other than that I don't see this failing on 2/4 pods other than by some obscure bug.

I also tested a bit to see the events in case of init container failure and I never saw Pulling image "node:18-alpine" event which is present in the events above, so I think init container executed successfully.

apiVersion: v1
kind: Pod
metadata:
  labels:
    pod: testing
  name: testing
spec:
  initContainers:
  - command:
    - sh
    - -c
    - exit 1
    image: busybox
    name: test-init
  containers:
  - image: node:18-alpine
    imagePullPolicy: IfNotPresent
    name: build
  restartPolicy: Never
  tolerations:
  - effect: NoSchedule
    key: gitlab-runner
    operator: Exists

$ kubectl get event --sort-by='.lastTimestamp'

LAST SEEN   TYPE      REASON                 OBJECT        MESSAGE
3m2s        Normal    Scheduled              pod/testing   Successfully assigned gitlab-runner/testing to ip-10-3-114-48.eu-central-1.compute.internal
3m2s        Normal    Pulling                pod/testing   Pulling image "busybox"
3m1s        Normal    Pulled                 pod/testing   Successfully pulled image "busybox" in 756ms (756ms including waiting)
3m1s        Normal    Created                pod/testing   Created container test-init
3m1s        Normal    Started                pod/testing   Started container test-init

[edsonmarquezani]

I'm also experiencing this issue. Certain pods are annotated with karpenter.sh/do-not-disrupt: "true" but their nodes are disrupted due to consolidation.

[engedaam]

@AleksaC Can you provide the pod describe to show what could be the reason the pod was evicted? Can share the events with timestamps, so we can compare when the eviction event was fired and when karpenter started terminating the node? Also are you seeing this happen regularly?

[edsonmarquezani]

@AleksaC I'm still investing, but it seems like I was just looking at the wrong place. The annotation actually shows up in nodes events (I was expecting to see it in Karpenter's logs). Regarding the eviction behavior, I'm still investigating but might not be triggered by Karpenter, after all.

[AleksaC]

@engedaam I cannot describe the original pods as they were gone by the time I was originally notified of the issue. It seems that naked pods get deleted upon eviction. Also the events aren't exported anywhere so they are gone now as well.

This is the first and only time it happened so far that I noticed. However this node pool isn't used often, as it's purpose is to handle spikes in CI jobs that node pool that doesn't have consolidation enabled cannot handle. As far as other node pools are concerned their workloads don't have pods that use this annotation.

I had an issue with a misbehaving HPA that would quickly scale up and down leading karpenter to provision a new node and then consolidate both the original and the new node leaving the pods from the original node in Pending state waiting for a new node to be spun up.

I only noticed this because one of the pods was from a Statefulset so it was pending a little longer than other pods, triggering our alerts. In this case I used the do-not-disrupt annotation on the pods for that statefulset to prevent the unnecessary consolidation until I fixed the HPA and it worked correctly AFAIK.