Uploaded image for project: 'OpenShift Virtualization'
  1. OpenShift Virtualization
  2. CNV-50195

With Descheduler, the virt-launcher-eviction-interceptor.kubevirt.io webhook errors on evicting, but it works anyway

XMLWordPrintable

    • 0.42
    • False
    • Hide

      None

      Show
      None
    • False
    • None
    • ---
    • ---
    • Medium
    • None

      Description of problem:

      This error always happens when the Descheduler evicts a VM from a node:
      
      E1024 01:27:17.901960       1 evictions.go:520] "Error evicting pod" err="error when evicting pod (ignoring) \"virt-launcher-centos-9-t45tz\": admission webhook \"virt-launcher-eviction-interceptor.kubevirt.io\" denied the request: Eviction triggered evacuation of VMI \"homelab/centos-9\"" pod="homelab/virt-launcher-centos-9-t45tz" reason=""

      Version-Release number of selected component (if applicable):

      OCP 4.17.2
      CNV 4.17.0
      Descheduler 5.1.0

      How reproducible:

      100%

      Steps to Reproduce:

      1. Follow the documentation at https://docs.openshift.com/container-platform/4.17/virt/virtual_machines/advanced_vm_management/virt-enabling-descheduler-evictions.html
      
      2. Start a very small VM with annotation descheduler.alpha.kubernetes.io/evict: 'true'
      
      3. Now place a very large VM on the same node (white.shift.home.arpa in this case) so it becomes overutilized
      
      4. Watch the Descheduler logs:
      
      I1024 01:27:17.875169       1 profile.go:318] "Total number of evictions/requests" extension point="Deschedule" evictedPods=0 evictionRequests=0
      I1024 01:27:17.875799       1 nodeutilization.go:210] "Node is appropriately utilized" node="yellow.shift.home.arpa" usage={"cpu":"789m","memory":"4663Mi","pods":"33"} usagePercentage={"cpu":22.54,"memory":15.21,"pods":13.2}
      I1024 01:27:17.875823       1 nodeutilization.go:210] "Node is appropriately utilized" node="black.shift.home.arpa" usage={"cpu":"895m","memory":"5663Mi","pods":"32"} usagePercentage={"cpu":25.57,"memory":18.41,"pods":12.8}
      I1024 01:27:17.875830       1 nodeutilization.go:210] "Node is appropriately utilized" node="green.shift.home.arpa" usage={"cpu":"2349m","memory":"9784Mi","pods":"66"} usagePercentage={"cpu":39.15,"memory":22.82,"pods":26.4}
      I1024 01:27:17.875838       1 nodeutilization.go:210] "Node is appropriately utilized" node="indigo.shift.home.arpa" usage={"cpu":"1019m","memory":"4307Mi","pods":"26"} usagePercentage={"cpu":29.11,"memory":6.85,"pods":10.4}
      I1024 01:27:17.875845       1 nodeutilization.go:204] "Node is underutilized" node="orange.shift.home.arpa" usage={"cpu":"1039m","memory":"4255Mi","pods":"26"} usagePercentage={"cpu":13.85,"memory":6.77,"pods":10.4}
      I1024 01:27:17.875854       1 nodeutilization.go:210] "Node is appropriately utilized" node="red.shift.home.arpa" usage={"cpu":"2306m","memory":"10658Mi","pods":"69"} usagePercentage={"cpu":38.43,"memory":24.86,"pods":27.6}
      I1024 01:27:17.875866       1 nodeutilization.go:207] "Node is overutilized" node="white.shift.home.arpa" usage={"cpu":"1509m","memory":"41344303105","pods":"24"} usagePercentage={"cpu":13.12,"memory":62.57,"pods":9.6}
      I1024 01:27:17.875876       1 nodeutilization.go:210] "Node is appropriately utilized" node="blue.shift.home.arpa" usage={"cpu":"1989m","memory":"7344Mi","pods":"38"} usagePercentage={"cpu":33.15,"memory":17.13,"pods":15.2}
      I1024 01:27:17.875883       1 nodeutilization.go:204] "Node is underutilized" node="violet.shift.home.arpa" usage={"cpu":"1403m","memory":"7047Mi","pods":"39"} usagePercentage={"cpu":18.71,"memory":11.21,"pods":15.6}
      I1024 01:27:17.875890       1 lownodeutilization.go:135] "Criteria for a node under utilization" CPU=20 Mem=20 Pods=20
      I1024 01:27:17.875900       1 lownodeutilization.go:136] "Number of underutilized nodes" totalNumber=2
      I1024 01:27:17.875906       1 lownodeutilization.go:149] "Criteria for a node above target utilization" CPU=50 Mem=50 Pods=50
      I1024 01:27:17.875911       1 lownodeutilization.go:150] "Number of overutilized nodes" totalNumber=1
      I1024 01:27:17.875917       1 nodeutilization.go:261] "Total capacity to be moved" CPU=5058 Mem=54061885440 Pods=185
      I1024 01:27:17.876001       1 nodeutilization.go:267] "Pods on node" node="white.shift.home.arpa" allPods=24 nonRemovablePods=23 removablePods=1
      I1024 01:27:17.876010       1 nodeutilization.go:274] "Evicting pods based on priority, if they have same priority, they'll be evicted based on QoS tiers"
      E1024 01:27:17.901960       1 evictions.go:520] "Error evicting pod" err="error when evicting pod (ignoring) \"virt-launcher-centos-9-t45tz\": admission webhook \"virt-launcher-eviction-interceptor.kubevirt.io\" denied the request: Eviction triggered evacuation of VMI \"homelab/centos-9\"" pod="homelab/virt-launcher-centos-9-t45tz" reason=""
      E1024 01:27:17.902001       1 nodeutilization.go:361] eviction failed: error when evicting pod (ignoring) "virt-launcher-centos-9-t45tz": admission webhook "virt-launcher-eviction-interceptor.kubevirt.io" denied the request: Eviction triggered evacuation of VMI "homelab/centos-9"
      I1024 01:27:17.902015       1 profile.go:347] "Total number of evictions/requests" extension point="Balance" evictedPods=0 evictionRequests=0
      I1024 01:27:17.902026       1 descheduler.go:183] "Number of evictions/requests" totalEvicted=0 evictionRequests=0
      
      5. The log above has errors when evicting and says it did not evict. But it did. Here is the live migration created at the same timestamp
      
      apiVersion: v1
      items:
      - apiVersion: kubevirt.io/v1
        kind: VirtualMachineInstanceMigration
        metadata:
          annotations:
            kubevirt.io/evacuationMigration: white.shift.home.arpa
            kubevirt.io/latest-observed-api-version: v1
            kubevirt.io/storage-observed-api-version: v1
          creationTimestamp: "2024-10-24T01:27:17Z"
          generateName: kubevirt-evacuation-
          generation: 1
          labels:
            kubevirt.io/vmi-name: centos-9
          name: kubevirt-evacuation-8cktp
          namespace: homelab
          resourceVersion: "5167498"
          uid: 79023b2c-2e3a-49fc-b94a-fd7189c9c14c
        spec:
          vmiName: centos-9
        status:
          migrationState:
            completed: true
            endTimestamp: "2024-10-24T01:27:24Z"
      
      6. Everything worked fine, but the logs are incorrect

      Actual results:

      * Errors in descheduler logs due to virt-launcher-eviction-interceptor.kubevirt.io webhook
      * Logs says 0 evictors were done, but it did one

      Expected results:

      Logs clean and correct

              lpivarc Luboslav Pivarc
              rhn-support-gveitmic Germano Veit Michel
              Kedar Bidarkar Kedar Bidarkar
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

                Created:
                Updated:
                Resolved: