Created attachment 1835877 [details] OCP UI showing events related to Live migration with 'DeadlineExceeded' exception Description of problem: Live migration of OpenShift Virtualization VMs with ODF based shared disks (with RWX access mode) is failing with exceptions like: "error encountered sending command SyncVMI.." Version-Release number of selected component (if applicable): 4.8.2 How reproducible: nearly 100% Steps to Reproduce: 1. Create an OpenShift Virtualization VM with disks based on openshift-ceph storage, shared access RWX of underlying PVC 2. Start Migration action using "Actions ==> Migrate" 3. Observe that VM gets into "Paused" state and check Events in the corresponding OpenShift UI Tab Actual results: Observed exception: ""Generated from virt-handler 219 times in the last 12 hours unknown error encountered sending command SyncVMI: rpc error: code = DeadlineExceeded desc = context deadline exceeded" Expected results: VM gets migrated to another OCP node preserving its state (storage based on RWX PVC) Additional info: Please see attached exports of VMs and corresponding KubeVirt POD YAML descriptors for VM that fails to Migrate. Can provide access to the Lab OCP cluster where the issue is observed
Created attachment 1835878 [details] PVC descriptor corresponding to VM disks
Created attachment 1835879 [details] pod-virt-launcher vortualization pod for failing to migrate VM
It appears that the migration is failing since the destination QEMU cannot obtain a write lock on the volume. {"component":"virt-launcher","level":"error","msg":"internal error: unable to execute QEMU command 'cont': Failed to get \"write\" lock","pos":"qemuMonitorJSONCheckErrorFull:418","subcomponent":"libvirt","thread":"41","timestamp":"2021-10-25T20:15:14.069000Z"} The source gets an IOError and the domain goes to pause. {"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Paused(3):IOError(5)","pos":"client.go:262","timestamp":"2021-10-25T20:15:38.892719Z"} Another troubling part is that libvirt doesn't release the job lock : "Cannot start job (modify, none, none) for domain vms_rhel8-random-snipe; current job is (query, none, none) owned by (46 remoteDispatchDomainGetDiskErrors, 0 \u003cnull\u003e, 0 \u003cnull\u003e (flags=0x0)) for (323s, 0s, 0s)","pos":"qemuDomainObjBeginJobInternal:953 {"component":"virt-launcher","level":"error","msg":"Timed out during operation: cannot acquire state change lock (held by monitor=remoteDispatchDomainGetDiskErrors)","pos":"qemuDomainObjBeginJobInternal:975","subcomponent":"libvirt","thread":"44","timestamp":"2021-10-25T20:21:02.056000Z"} {"component":"virt-launcher","kind":"","level":"error","msg":"unpausing the VirtualMachineInstance failed.","name":"rhel8-random-snipe","namespace":"vms","pos":"manager.go:799","reason":"virError(Code=68, Domain=10, Message='Timed out during operation: cannot acquire state change lock (held by monitor=remoteDispatchDomainGetDiskErrors)')","timestamp":"2021-10-25T20:21:02.056507Z","uid":"8408ef2d-20a1-41df-962d-a68600713f1e"} {"component":"virt-launcher","kind":"","level":"error","msg":"Failed to sync vmi","name":"rhel8-random-snipe","namespace":"vms","pos":"server.go:182","reason":"virError(Code=68, Domain=10, Message='Timed out during operation: cannot acquire state change lock (held by monitor=remoteDispatchDomainGetDiskErrors)')","timestamp":"2021-10-25T20:21:02.056576Z","uid":"8408ef2d-20a1-41df-962d-a68600713f1e"}
We should reproduce this issue with more verbose logs. The logs verbosity can be increased by updating the Hyperconverged cluster operator as in the following example: https://github.com/kubevirt/hyperconverged-cluster-operator/blob/main/docs/cluster-configuration.md#examples Setting virtLauncher setting to 5 above will enable the libvirt debug logs. This will allow us to understand which volume is being locked and will provide more insight into the libvirt flow.
An update (not directly related to the bug, but to the OPenShift VMs live migration use case): Using RBD Block mode PVC option (per documentation https://docs.openshift.com/container-platform/4.8/virt/virtual_machines/virtual_disks/virt-configuring-local-storage-for-vms.html), we were able to perform a live migration of OpenShift Virtualization VMS with disks based on PVCs using that mode. (Use 'ocs-storagecluster-ceph-rbd' storage class and 'VolumeMode: Block') The documentation advises to prefer RBD mode since "..With virtual machine disks, RBD block mode volumes are more efficient and provide better performance than Ceph FS or RBD filesystem-mode PVCs." but it doesn't advise against using Ceph FS mode explicitly. Will try to obtain more verbose libVirt logs tomorrow 10/26.
Daniel, How would you like to proceed? Should we close this BZ and reopen when/if it'll become relevant again?
Hi Vladik, I think this will be a fair approach at this point as we have found a workaround for this scenario in OCP 4.8.2 If it re-occurs, I will reopen the issue. Thanks for your analysis so far. Dan Zilberman