Created attachment 1776743 [details] VM, VMI yamls and virt-launcher pod Description of problem: VMs (running or not) cannot be deleted. Version-Release number of selected component (if applicable): CNV 4.8.0 virt-operator v4.8.0-46 How reproducible: 100% Steps to Reproduce: 1. Create a VM 2. (either start it or not) 3. Delete the VM Actual results: VM is not deleted (if the VM is running; VMI and virt-launcher pod are not deleted either) Expected results: VM should be deleted. Additional info: ====== VM ====== VM and VMI yamls attached as well as vir-launcher pod --- apiVersion: kubevirt.io/v1 kind: VirtualMachine metadata: labels: kubevirt.io/vm: vm-cirros114 name: vm-cirros114 spec: running: false template: metadata: labels: kubevirt.io/vm: vm-cirros114 spec: domain: devices: disks: - disk: bus: virtio name: containerdisk - disk: bus: virtio name: cloudinitdisk machine: type: "" resources: requests: memory: 128Mi terminationGracePeriodSeconds: 0 volumes: - containerDisk: image: kubevirt/cirros-container-disk-demo:latest name: containerdisk - cloudInitNoCloud: userData: | #!/bin/sh echo 'printed from cloud-init userdata' name: cloudinitdisk
$ oc logs -n openshift-cnv virt-api-599947b948-tv2c8 | grep cirros112 {"component":"virt-api","contentLength":0,"level":"info","method":"PUT","pos":"filter.go:46","proto":"HTTP/1.1","remoteAddress":"10.130.0.1","statusCode":202,"timestamp":"2021-04-28T14:07:21.863738Z","url":"/apis/subresources.kubevirt.io/v1alpha3/namespaces/default/virtualmachines/vm-cirros112/start","username":"-"} [cnv-qe-jenkins@ruty-480-28-nf2ll-executor ~]$ oc logs -n openshift-cnv virt-api-599947b948-tv2c8 | grep "cirros112\|ee0ae3d5600f" {"component":"virt-api","contentLength":0,"level":"info","method":"PUT","pos":"filter.go:46","proto":"HTTP/1.1","remoteAddress":"10.130.0.1","statusCode":202,"timestamp":"2021-04-28T14:07:21.863738Z","url":"/apis/subresources.kubevirt.io/v1alpha3/namespaces/default/virtualmachines/vm-cirros112/start","username":"-"} $ oc logs -n openshift-cnv virt-handler-jh999 | grep "cirros112\|ee0ae3d5600f" {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:07:30.519671Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:07:30.519739Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at /var/lib/containers/storage/overlay/22b3789c4effbb618dc6ab9f3678926281d9b47502d2fecc1f7fcad58f8f8a9b/merged/disk/downloaded to /var/lib/kubelet/pods/704e45b6-1fcf-45b7-a8b4-989d418edb57/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"vm-cirros112","namespace":"default","pos":"mount.go:250","timestamp":"2021-04-28T14:07:30.527095Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"","level":"info","msg":"Accepted new notify pipe connection for vmi","name":"vm-cirros112","namespace":"default","pos":"vm.go:331","timestamp":"2021-04-28T14:07:31.455614Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Received Domain Event of type ADDED","name":"vm-cirros112","namespace":"default","pos":"server.go:78","timestamp":"2021-04-28T14:07:31.457581Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain is in state Shutoff reason Unknown","name":"vm-cirros112","namespace":"default","pos":"vm.go:2596","timestamp":"2021-04-28T14:07:31.457678Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Received Domain Event of type MODIFIED","name":"vm-cirros112","namespace":"default","pos":"server.go:78","timestamp":"2021-04-28T14:07:31.458499Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Received Domain Event of type MODIFIED","name":"vm-cirros112","namespace":"default","pos":"server.go:78","timestamp":"2021-04-28T14:07:31.545833Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain is in state Paused reason StartingUp","name":"vm-cirros112","namespace":"default","pos":"vm.go:2626","timestamp":"2021-04-28T14:07:31.545962Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Received Domain Event of type MODIFIED","name":"vm-cirros112","namespace":"default","pos":"server.go:78","timestamp":"2021-04-28T14:07:31.996485Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain is in state Running reason Unknown","name":"vm-cirros112","namespace":"default","pos":"vm.go:2626","timestamp":"2021-04-28T14:07:31.996626Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Received Domain Event of type MODIFIED","name":"vm-cirros112","namespace":"default","pos":"server.go:78","timestamp":"2021-04-28T14:07:32.004511Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:07:32.015289Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:07:32.015355Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain status: Running, reason: Unknown\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1519","timestamp":"2021-04-28T14:07:32.015396Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:07:32.032770Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:07:32.032824Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain status: Running, reason: Unknown\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1519","timestamp":"2021-04-28T14:07:32.032851Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:07:32.047553Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:07:32.047609Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain status: Running, reason: Unknown\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1519","timestamp":"2021-04-28T14:07:32.047652Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:07:32.074798Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:07:32.074869Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain status: Running, reason: Unknown\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1519","timestamp":"2021-04-28T14:07:32.074914Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:07:42.482148Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:07:42.482217Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain status: Running, reason: Unknown\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1519","timestamp":"2021-04-28T14:07:42.482243Z","uid":""} {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:12:42.484217Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:12:42.484276Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain status: Running, reason: Unknown\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1519","timestamp":"2021-04-28T14:12:42.484300Z","uid":""} {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:17:42.483056Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:17:42.483114Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain status: Running, reason: Unknown\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1519","timestamp":"2021-04-28T14:17:42.483148Z","uid":""} {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:22:42.484625Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:22:42.484673Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain status: Running, reason: Unknown\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1519","timestamp":"2021-04-28T14:22:42.484712Z","uid":""} {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:27:42.482914Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:27:42.482965Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain status: Running, reason: Unknown\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1519","timestamp":"2021-04-28T14:27:42.482990Z","uid":""} {"component":"virt-handler","level":"info","msg":"Processing event default/vm-cirros112","pos":"vm.go:1512","timestamp":"2021-04-28T14:32:42.482617Z"} {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1514","timestamp":"2021-04-28T14:32:42.482674Z","uid":"27413a57-ed14-4e93-aff6-c780a11ae925"} {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain status: Running, reason: Unknown\n","name":"vm-cirros112","namespace":"default","pos":"vm.go:1519","timestamp":"2021-04-28T14:32:42.482712Z","uid":""}
Created attachment 1776771 [details] VMs in UI console
From Ram: "In short, kubemacpool needs to wait for kubevirt to appear, but it doesn't do that now since kubevirt is not waited for, the VM controller is not created, and as a consequence, when vms are deleted, the VM controller is not there to remove the finalizer"
PR to solve this. https://github.com/k8snetworkplumbingwg/kubemacpool/pull/292
Hi Before verifying this bug, make sure that during this particular deployment, kubemacpool was present before kubevirt was ready - otherwise the scenario was not reproduced. An easy way to check this is by checking the kubemacpool logs like so: oc logs -n openshift-cnv <kubemacpool-pod-name> | grep "kubevirt was not found in the cluster start a watching process"
Verified with kubemacpool-mac-controller-manager v4.8.0-14 - Verified that kubemacpool was present before kubevirt was ready: $ oc logs -n openshift-cnv kubemacpool-mac-controller-manager-6d46fb95d5-hrkfw |grep "kubevirt was not found" {"level":"info","ts":1620585745.117114,"logger":"manager","msg":"kubevirt was not found in the cluster start a watching process"} - VMs can be deleted
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory (Moderate: OpenShift Virtualization 4.8.0 Images), and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHSA-2021:2920