kubevirt minikube network error

virt-handler.log

{"component":"virt-handler","hostname":"minikube","level":"info","pos":"virt-handler.go:198","timestamp":"2023-01-16T10:46:00.541930Z"}
W0116 10:46:00.542715   22154 client_config.go:617] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
{"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:471","timestamp":"2023-01-16T10:46:00.566341Z"}
{"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:471","timestamp":"2023-01-16T10:46:00.566625Z"}
{"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:480","timestamp":"2023-01-16T10:46:00.566687Z"}
{"component":"virt-handler","level":"warning","msg":"host model mode is expected to contain only one model","pos":"cpu_plugin.go:98","timestamp":"2023-01-16T10:46:00.586780Z"}
{"component":"virt-handler","level":"info","msg":"node-labeller is running","pos":"node_labeller.go:110","timestamp":"2023-01-16T10:46:00.587721Z"}
{"component":"virt-handler","level":"info","msg":"Starting domain stats collector: node name=minikube","pos":"prometheus.go:531","timestamp":"2023-01-16T10:46:00.588278Z"}
{"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:471","timestamp":"2023-01-16T10:46:00.589727Z"}
{"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:480","timestamp":"2023-01-16T10:46:00.589749Z"}
{"component":"virt-handler","level":"info","msg":"STARTING informer vmiInformer-sources","pos":"virtinformers.go:330","timestamp":"2023-01-16T10:46:00.589703Z"}
{"component":"virt-handler","level":"info","msg":"STARTING informer vmiInformer-targets","pos":"virtinformers.go:330","timestamp":"2023-01-16T10:46:00.589805Z"}
{"component":"virt-handler","level":"info","msg":"STARTING informer CRDInformer","pos":"virtinformers.go:330","timestamp":"2023-01-16T10:46:00.589845Z"}
{"component":"virt-handler","level":"info","msg":"STARTING informer kubeVirtInformer","pos":"virtinformers.go:330","timestamp":"2023-01-16T10:46:00.589898Z"}
{"component":"virt-handler","level":"info","msg":"STARTING informer extensionsKubeVirtCAConfigMapInformer","pos":"virtinformers.go:330","timestamp":"2023-01-16T10:46:00.589934Z"}
{"component":"virt-handler","level":"info","msg":"certificate with common name 'kubevirt.io:system:node:virt-handler' retrieved.","pos":"cert-manager.go:198","timestamp":"2023-01-16T10:46:00.590074Z"}
{"component":"virt-handler","level":"info","msg":"metrics: max concurrent requests=3","pos":"virt-handler.go:495","timestamp":"2023-01-16T10:46:00.588429Z"}
{"component":"virt-handler","level":"info","msg":"certificate with common name 'kubevirt.io:system:client:virt-handler' retrieved.","pos":"cert-manager.go:198","timestamp":"2023-01-16T10:46:00.590471Z"}
{"component":"virt-handler","level":"info","msg":"Updating cluster config from KubeVirt to resource version '1049'","pos":"configuration.go:320","timestamp":"2023-01-16T10:46:00.627728Z"}
{"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:471","timestamp":"2023-01-16T10:46:00.627760Z"}
{"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:480","timestamp":"2023-01-16T10:46:00.627773Z"}
{"component":"virt-handler","level":"info","msg":"Starting virt-handler controller.","pos":"vm.go:1387","timestamp":"2023-01-16T10:46:00.725772Z"}
{"component":"virt-handler","level":"info","msg":"Starting a device plugin for device: kvm","pos":"device_controller.go:57","timestamp":"2023-01-16T10:46:00.725983Z"}
{"component":"virt-handler","level":"info","msg":"Starting a device plugin for device: tun","pos":"device_controller.go:57","timestamp":"2023-01-16T10:46:00.726058Z"}
{"component":"virt-handler","level":"info","msg":"Starting a device plugin for device: vhost-net","pos":"device_controller.go:57","timestamp":"2023-01-16T10:46:00.726078Z"}
{"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:320","timestamp":"2023-01-16T10:46:00.726130Z"}
{"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:321","timestamp":"2023-01-16T10:46:00.726178Z"}
{"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:322","timestamp":"2023-01-16T10:46:00.726199Z"}
{"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:320","timestamp":"2023-01-16T10:46:00.726224Z"}
{"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:321","timestamp":"2023-01-16T10:46:00.726261Z"}
{"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:322","timestamp":"2023-01-16T10:46:00.726283Z"}
{"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:471","timestamp":"2023-01-16T10:46:00.726826Z"}
{"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:480","timestamp":"2023-01-16T10:46:00.726886Z"}
{"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:480","timestamp":"2023-01-16T10:46:00.728326Z"}
{"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:471","timestamp":"2023-01-16T10:46:00.733524Z"}
{"component":"virt-handler","level":"info","msg":"vhost-net device plugin started","pos":"generic_device.go:161","timestamp":"2023-01-16T10:46:00.735165Z"}
{"component":"virt-handler","level":"info","msg":"device '/dev/vhost-net' is present.","pos":"generic_device.go:310","timestamp":"2023-01-16T10:46:00.735264Z"}
{"component":"virt-handler","level":"info","msg":"tun device plugin started","pos":"generic_device.go:161","timestamp":"2023-01-16T10:46:00.743227Z"}
{"component":"virt-handler","level":"info","msg":"device '/dev/net/tun' is present.","pos":"generic_device.go:310","timestamp":"2023-01-16T10:46:00.743368Z"}
{"component":"virt-handler","level":"info","msg":"kvm device plugin started","pos":"generic_device.go:161","timestamp":"2023-01-16T10:46:00.746545Z"}
{"component":"virt-handler","level":"info","msg":"device '/dev/kvm' is present.","pos":"generic_device.go:310","timestamp":"2023-01-16T10:46:00.746683Z"}
{"component":"virt-handler","level":"info","msg":"Updating cluster config from KubeVirt to resource version '2686'","pos":"configuration.go:320","timestamp":"2023-01-16T10:46:01.270735Z"}
{"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:480","timestamp":"2023-01-16T10:46:01.271887Z"}
{"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:471","timestamp":"2023-01-16T10:46:01.271908Z"}
{"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:320","timestamp":"2023-01-16T10:46:01.272006Z"}
{"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:321","timestamp":"2023-01-16T10:46:01.272021Z"}
{"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:322","timestamp":"2023-01-16T10:46:01.272028Z"}
W0116 10:46:18.893066   22154 client_config.go:617] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
{"component":"virt-handler","level":"info","msg":"Updating cluster config from KubeVirt to resource version '2733'","pos":"configuration.go:320","timestamp":"2023-01-16T10:46:23.993069Z"}
{"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:480","timestamp":"2023-01-16T10:46:23.993731Z"}
{"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:320","timestamp":"2023-01-16T10:46:23.993822Z"}
{"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:321","timestamp":"2023-01-16T10:46:23.993889Z"}
{"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:322","timestamp":"2023-01-16T10:46:23.993926Z"}
{"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:471","timestamp":"2023-01-16T10:46:23.994073Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T10:50:37.121838Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net988],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:50:37.122005Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T10:50:37.125251Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm619],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:50:37.125327Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T10:50:37.127104Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun469],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:50:37.127154Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:50:52.212267Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T10:50:52.218089Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/14a0c89b95d1a0f059f01f5251b57ec61e79578d6478a3c8ea18eccd65250869/merged/disk/downloaded to root: /var/lib/kubelet/pods/b33dfed6-dc18-41b5-8871-8d692d081956/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T10:50:52.218485Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T10:50:52.255444Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T10:50:52.255541Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T10:50:52.269451Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T10:50:52.294917Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 26626","pos":"common.go:390","timestamp":"2023-01-16T10:50:52.295010Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T10:50:52.295793Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T10:50:52.305993Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T10:50:52.306070Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T10:50:52.306217Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T10:50:52.307143Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T10:50:52.307221Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T10:50:52.307373Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T10:50:52.322136Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:50:52.322184Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid e9b2eb0d-0e9e-4c85-941d-81692b135bc1","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:50:52.322232Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T10:50:52.322259Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/b33dfed6-dc18-41b5-8871-8d692d081956/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T10:50:52.322274Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/b33dfed6-dc18-41b5-8871-8d692d081956/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T10:50:52.322347Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:50:52.359437Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T10:50:52.359681Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:50:52.363104Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:50:52.363253Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid e9b2eb0d-0e9e-4c85-941d-81692b135bc1","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:50:52.363357Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T10:50:52.363444Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:50:52.363462Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:50:52.363565Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:50:52.372568Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid e9b2eb0d-0e9e-4c85-941d-81692b135bc1","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:50:52.372621Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T10:50:52.374278Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:50:52.374707Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:50:52.375156Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:50:52.389568Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid e9b2eb0d-0e9e-4c85-941d-81692b135bc1","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:50:52.389623Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T10:50:52.390481Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:50:52.390504Z","uid":"e9b2eb0d-0e9e-4c85-941d-81692b135bc1"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:50:52.390560Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T10:50:56.317118Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:50:56.317154Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:50:56.317175Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T10:51:00.626850Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T10:51:04.385354Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm110],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:51:04.385888Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T10:51:04.387562Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun249],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:51:04.387674Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T10:51:04.388733Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net932],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:51:04.388837Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:51:13.736431Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T10:51:13.739279Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/b6abf248d868f1c0a00ad06f2926e85dff61777a83f6dfe3737aefb9c53e5537/merged/disk/downloaded to root: /var/lib/kubelet/pods/23368b38-275d-4d23-86b0-fedb16e971b2/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T10:51:13.739482Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T10:51:13.773988Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T10:51:13.774032Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T10:51:13.786902Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T10:51:13.811329Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 27486","pos":"common.go:390","timestamp":"2023-01-16T10:51:13.811391Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T10:51:13.811792Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T10:51:13.819796Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T10:51:13.819832Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T10:51:13.819915Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T10:51:13.820026Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T10:51:13.820048Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T10:51:13.820071Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T10:51:13.829480Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:51:13.833344Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 6cb53c27-2d59-4655-a79c-c064bb92f941","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:51:13.833681Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T10:51:13.833782Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/23368b38-275d-4d23-86b0-fedb16e971b2/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T10:51:13.833893Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/23368b38-275d-4d23-86b0-fedb16e971b2/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T10:51:13.834042Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:51:13.867653Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:51:13.867840Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:51:13.867971Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 6cb53c27-2d59-4655-a79c-c064bb92f941","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:51:13.868034Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T10:51:13.868102Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:51:13.868157Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:51:13.868229Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T10:51:13.867934Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:51:13.887786Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 6cb53c27-2d59-4655-a79c-c064bb92f941","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:51:13.887985Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T10:51:13.888079Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:51:13.888149Z","uid":"6cb53c27-2d59-4655-a79c-c064bb92f941"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:51:13.888228Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T10:51:17.840429Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:51:17.840463Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:51:17.840656Z","uid":""}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T10:52:13.887182Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net393],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:52:13.887239Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T10:52:13.887940Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm881],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:52:13.887982Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T10:52:13.890198Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun365],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:52:13.890262Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:52:23.175905Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T10:52:23.178268Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/b909ebc8fa7b4e4700d73612fc2847f1ad25c8586b2c2b10ed1a43d10abeed47/merged/disk/downloaded to root: /var/lib/kubelet/pods/11b0386b-818a-4c2d-b0c4-932dee1c3ee6/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T10:52:23.178509Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T10:52:23.212531Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T10:52:23.212591Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T10:52:23.226561Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T10:52:23.250795Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 29033","pos":"common.go:390","timestamp":"2023-01-16T10:52:23.250840Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T10:52:23.251083Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T10:52:23.260088Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T10:52:23.260119Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T10:52:23.260163Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T10:52:23.260239Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T10:52:23.260256Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T10:52:23.260273Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T10:52:23.270297Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:52:23.270496Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 63ef6da6-2259-4ea6-9df4-d52d8caf1d10","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:52:23.270540Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T10:52:23.270559Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/11b0386b-818a-4c2d-b0c4-932dee1c3ee6/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T10:52:23.270666Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/11b0386b-818a-4c2d-b0c4-932dee1c3ee6/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T10:52:23.271194Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:52:23.355008Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:52:23.360998Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:52:23.361209Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 63ef6da6-2259-4ea6-9df4-d52d8caf1d10","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:52:23.361303Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T10:52:23.361380Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:52:23.361437Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:52:23.361517Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T10:52:23.361161Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:52:23.374423Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 63ef6da6-2259-4ea6-9df4-d52d8caf1d10","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:52:23.375365Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T10:52:23.375459Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:52:23.375518Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:52:23.375567Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:52:23.388305Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 63ef6da6-2259-4ea6-9df4-d52d8caf1d10","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:52:23.388609Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T10:52:23.388784Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:52:23.388892Z","uid":"63ef6da6-2259-4ea6-9df4-d52d8caf1d10"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:52:23.389008Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T10:52:27.326255Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:52:27.326291Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:52:27.326319Z","uid":""}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T10:54:02.413245Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm987],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:54:02.414340Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T10:54:02.416639Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun384],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:54:02.416692Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T10:54:02.419287Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net817],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:54:02.419456Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:54:12.441746Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T10:54:12.444366Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/16a7c98609be5125bf78cdeadafa08d6a38f5d061b708af5c6d2784d87891dfb/merged/disk/downloaded to root: /var/lib/kubelet/pods/f1b82422-ec2a-47e3-abdb-d3c8148a9ca4/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T10:54:12.445371Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T10:54:12.478056Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T10:54:12.478195Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T10:54:12.491391Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T10:54:12.515961Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 31115","pos":"common.go:390","timestamp":"2023-01-16T10:54:12.516042Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T10:54:12.516367Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T10:54:12.524557Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T10:54:12.524619Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T10:54:12.524737Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T10:54:12.524824Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T10:54:12.524881Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T10:54:12.524922Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T10:54:12.537701Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:54:12.538668Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 03bc2f74-4848-4645-a9af-4662e25cda3c","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:54:12.539396Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T10:54:12.539542Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/f1b82422-ec2a-47e3-abdb-d3c8148a9ca4/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T10:54:12.539612Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/f1b82422-ec2a-47e3-abdb-d3c8148a9ca4/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T10:54:12.539894Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:54:12.601274Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:54:12.601484Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:54:12.601559Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T10:54:12.601623Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 03bc2f74-4848-4645-a9af-4662e25cda3c","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:54:12.601672Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T10:54:12.601743Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:54:12.601790Z","uid":"03bc2f74-4848-4645-a9af-4662e25cda3c"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:54:12.601910Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T10:54:16.568646Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:54:16.568698Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:54:16.568724Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T10:56:00.627008Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T10:58:00.681842Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun248],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:58:00.682092Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T10:58:00.684415Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net688],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:58:00.684704Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T10:58:00.686081Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm776],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T10:58:00.686116Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:58:09.893354Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T10:58:09.895356Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/49c081c9280fe37cf64d087f11e6b35de4324eafc0beaf582109d89d1e0ae373/merged/disk/downloaded to root: /var/lib/kubelet/pods/170ad1d5-4ea5-418d-931c-10a7d009187f/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T10:58:09.895573Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T10:58:09.926266Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T10:58:09.926306Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T10:58:09.940977Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T10:58:09.975423Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 34966","pos":"common.go:390","timestamp":"2023-01-16T10:58:09.975471Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T10:58:09.975827Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T10:58:09.983924Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T10:58:09.983953Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T10:58:09.984008Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T10:58:09.984107Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T10:58:09.984132Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T10:58:09.984168Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T10:58:09.997799Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:58:09.999008Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 77f3d7a7-7b14-44e3-b1bc-ef48b440cba5","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:58:09.999073Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T10:58:09.999918Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/170ad1d5-4ea5-418d-931c-10a7d009187f/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T10:58:09.999968Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/170ad1d5-4ea5-418d-931c-10a7d009187f/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T10:58:10.000201Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:58:10.059589Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:58:10.059740Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T10:58:10.059898Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T10:58:10.059987Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 77f3d7a7-7b14-44e3-b1bc-ef48b440cba5","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:58:10.060026Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T10:58:10.060120Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T10:58:10.060136Z","uid":"77f3d7a7-7b14-44e3-b1bc-ef48b440cba5"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:58:10.060226Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T10:58:13.993261Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T10:58:13.993295Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T10:58:13.993316Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:01:00.627076Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:02:42.087784Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm39],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:02:42.087906Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:02:42.088619Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun485],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:02:42.088673Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:02:42.089219Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net183],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:02:42.091171Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:02:52.072835Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:02:52.074838Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/b8e71718832a9b6ac8cf6e9ccbe1728a2364ef3607a9a85964ab3e61dd8b689c/merged/disk/downloaded to root: /var/lib/kubelet/pods/85e79554-a269-4242-a64d-625f68d9b217/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:02:52.075030Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:02:52.111841Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:02:52.111911Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:02:52.125404Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:02:52.148843Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 39573","pos":"common.go:390","timestamp":"2023-01-16T11:02:52.148908Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:02:52.149097Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:02:52.156560Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:02:52.156593Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:02:52.156647Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:02:52.156715Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:02:52.156731Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:02:52.156751Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:02:52.166967Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:02:52.167446Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 045d2e2b-328b-4cdc-a8fe-e8c5b3e45389","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:02:52.167537Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:02:52.167607Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/85e79554-a269-4242-a64d-625f68d9b217/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:02:52.167659Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/85e79554-a269-4242-a64d-625f68d9b217/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:02:52.167808Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:02:52.208693Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:02:52.209200Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:02:52.209379Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 045d2e2b-328b-4cdc-a8fe-e8c5b3e45389","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:02:52.209454Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:02:52.209524Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:02:52.209575Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:02:52.209651Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:02:52.209341Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:02:52.216581Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 045d2e2b-328b-4cdc-a8fe-e8c5b3e45389","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:02:52.216628Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:02:52.216657Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:02:52.216673Z","uid":"045d2e2b-328b-4cdc-a8fe-e8c5b3e45389"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:02:52.216707Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:02:56.223069Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:02:56.223275Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:02:56.223446Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:06:00.627306Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:07:52.293091Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm317],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:07:52.293536Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:07:52.294162Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun212],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:07:52.294212Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:07:52.294693Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net851],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:07:52.294748Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:08:01.781301Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:08:01.785069Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/72b8c265e77250f8adeba188ed0ab5bdc51acf9815743e083f49ce0735c37217/merged/disk/downloaded to root: /var/lib/kubelet/pods/11118960-09f3-4fbc-9f9d-8b76c14828c3/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:08:01.785257Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:08:01.817306Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:08:01.817347Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:08:01.830091Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:08:01.854099Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 44654","pos":"common.go:390","timestamp":"2023-01-16T11:08:01.854142Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:08:01.854458Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:08:01.861408Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:08:01.861437Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:08:01.861501Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:08:01.861845Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:08:01.861876Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:08:01.861898Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:08:01.871132Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:08:01.874941Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 56004906-1f40-4dab-af40-316160b6277e","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:08:01.875002Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:08:01.875025Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/11118960-09f3-4fbc-9f9d-8b76c14828c3/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:08:01.879070Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/11118960-09f3-4fbc-9f9d-8b76c14828c3/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:08:01.879264Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:08:01.903507Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:08:01.903729Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:08:01.903802Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 56004906-1f40-4dab-af40-316160b6277e","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:08:01.903880Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:08:01.903974Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:08:01.904039Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:08:01.903817Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:08:01.904147Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:08:01.914444Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 56004906-1f40-4dab-af40-316160b6277e","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:08:01.914499Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:08:01.915418Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:08:01.915565Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:08:01.915705Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:08:01.931307Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 56004906-1f40-4dab-af40-316160b6277e","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:08:01.931892Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:08:01.931988Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:08:01.932051Z","uid":"56004906-1f40-4dab-af40-316160b6277e"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:08:01.932137Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:08:04.881401Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:08:04.881439Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:08:04.881469Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:11:00.626352Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:13:01.955219Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm342],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:13:01.955408Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:13:01.957187Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun102],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:13:01.957235Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:13:01.958659Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net7],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:13:01.958781Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:13:11.530973Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:13:11.533031Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/88206539fce200bb532b58405f8eec6ae248aba982d15425ad0f648ffd8cf5a4/merged/disk/downloaded to root: /var/lib/kubelet/pods/144d2389-24e9-4194-8fc6-dc65c529ebb8/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:13:11.533222Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:13:11.564512Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:13:11.564596Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:13:11.578974Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:13:11.604492Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 49566","pos":"common.go:390","timestamp":"2023-01-16T11:13:11.604564Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:13:11.604777Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:13:11.612617Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:13:11.612654Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:13:11.612703Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:13:11.612768Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:13:11.612784Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:13:11.612809Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:13:11.624557Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:13:11.624696Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 197b971b-9b07-45a1-b6f6-3d2555e0bf26","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:13:11.625819Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:13:11.626264Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/144d2389-24e9-4194-8fc6-dc65c529ebb8/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:13:11.626304Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/144d2389-24e9-4194-8fc6-dc65c529ebb8/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:13:11.626547Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:13:11.670192Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:13:11.670407Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:13:11.670527Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 197b971b-9b07-45a1-b6f6-3d2555e0bf26","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:13:11.670644Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:13:11.670700Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:13:11.670732Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:13:11.670777Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:13:11.670483Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:13:11.683100Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 197b971b-9b07-45a1-b6f6-3d2555e0bf26","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:13:11.683261Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:13:11.683357Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:13:11.683393Z","uid":"197b971b-9b07-45a1-b6f6-3d2555e0bf26"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:13:11.683499Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:13:15.675409Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:13:15.675512Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:13:15.675548Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:16:00.626920Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:18:11.768999Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm187],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:18:11.769074Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:18:11.770906Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun325],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:18:11.770941Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:18:11.775822Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net624],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:18:11.775928Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:18:21.718386Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:18:21.720181Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/044717813b95bf8c304792999c6ad7e8f1a4ad9bfbce8079bc1eb8e25a73aa12/merged/disk/downloaded to root: /var/lib/kubelet/pods/417218bd-f158-41cb-93cc-8305c5ecc0af/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:18:21.720355Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:18:21.750738Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:18:21.750780Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:18:21.767944Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:18:21.791613Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 54504","pos":"common.go:390","timestamp":"2023-01-16T11:18:21.791654Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:18:21.791962Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:18:21.799561Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:18:21.799591Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:18:21.799637Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:18:21.799714Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:18:21.799731Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:18:21.799749Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:18:21.809159Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:18:21.810195Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:18:21.810483Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:18:21.810587Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/417218bd-f158-41cb-93cc-8305c5ecc0af/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:18:21.810608Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/417218bd-f158-41cb-93cc-8305c5ecc0af/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:18:21.810760Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:18:21.841808Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:18:21.846667Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:18:21.846639Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:18:21.846834Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:18:21.846993Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:18:21.847211Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:18:21.847234Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:18:21.847476Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:18:21.863573Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:18:21.863624Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:18:21.863649Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:18:21.863921Z","uid":"8cb5c04e-d97b-40ed-9195-6acd2bc6fd7d"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:18:21.864014Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:18:25.838739Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:18:25.838778Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:18:25.838807Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:21:00.627110Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:23:21.917979Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net543],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:23:21.918031Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:23:21.918933Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm849],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:23:21.918983Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:23:21.919819Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun835],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:23:21.919870Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:23:31.900217Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:23:31.903158Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/0bbf695d375da6b4272f78d85610e7a02c98186bf75277f2b372a344b91ded8a/merged/disk/downloaded to root: /var/lib/kubelet/pods/2410e3fc-181b-483e-af9e-fdb736581c10/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:23:31.903342Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:23:31.940216Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:23:31.940407Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:23:31.953017Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:23:31.980859Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 59554","pos":"common.go:390","timestamp":"2023-01-16T11:23:31.981002Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:23:31.981326Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:23:31.989019Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:23:31.989196Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:23:31.989327Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:23:31.989527Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:23:31.989612Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:23:31.990939Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:23:32.001390Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:23:32.004603Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid de96667a-4616-45d0-858f-b29aff5e37b9","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:23:32.004677Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:23:32.004716Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/2410e3fc-181b-483e-af9e-fdb736581c10/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:23:32.004739Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/2410e3fc-181b-483e-af9e-fdb736581c10/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:23:32.004855Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:23:32.063310Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:23:32.063466Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:23:32.063516Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid de96667a-4616-45d0-858f-b29aff5e37b9","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:23:32.063549Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:23:32.063584Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:23:32.063606Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:23:32.063659Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:23:32.063723Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:23:32.077774Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid de96667a-4616-45d0-858f-b29aff5e37b9","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:23:32.077943Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:23:32.078078Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:23:32.078149Z","uid":"de96667a-4616-45d0-858f-b29aff5e37b9"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:23:32.078265Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:23:36.071453Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:23:36.071490Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:23:36.071512Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:26:00.626422Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:28:32.919469Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm477],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:28:32.919845Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:28:32.944919Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun862],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:28:32.945414Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:28:33.061413Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net794],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:28:33.081933Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:28:50.249617Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:28:50.272693Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/c7a4c536a3ed83794f255e52bf5125ba3bf2f483e6f096edc288d14deecf3b14/merged/disk/downloaded to root: /var/lib/kubelet/pods/b4ed999e-1e47-49ae-9f02-cce1f28e3b65/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:28:50.274921Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:28:50.476968Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:28:50.477198Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:28:50.574594Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:28:50.745348Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 64483","pos":"common.go:390","timestamp":"2023-01-16T11:28:50.745485Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:28:50.747469Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:28:50.796934Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:28:50.797148Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:28:50.797496Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:28:50.798112Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:28:50.798243Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:28:50.798399Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:28:50.864830Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:28:50.867279Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 4312699f-a93b-4a30-84ae-58cbde8dcefa","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:28:50.881254Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:28:50.882158Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/b4ed999e-1e47-49ae-9f02-cce1f28e3b65/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:28:50.882738Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/b4ed999e-1e47-49ae-9f02-cce1f28e3b65/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:28:50.886341Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:28:51.228461Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:28:51.228929Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:28:51.229147Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 4312699f-a93b-4a30-84ae-58cbde8dcefa","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:28:51.229249Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:28:51.229394Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:28:51.229466Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:28:51.229843Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:28:51.230612Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:28:51.325062Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 4312699f-a93b-4a30-84ae-58cbde8dcefa","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:28:51.325318Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:28:51.326456Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:28:51.326582Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:28:51.326943Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:28:51.451610Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 4312699f-a93b-4a30-84ae-58cbde8dcefa","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:28:51.453389Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:28:51.454034Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:28:51.454123Z","uid":"4312699f-a93b-4a30-84ae-58cbde8dcefa"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:28:51.455176Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:28:55.795251Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:28:55.796018Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:28:55.796671Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:31:00.626643Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:33:50.851553Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun234],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:33:50.851623Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:33:50.853730Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net785],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:33:50.853772Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:33:50.854344Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm918],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:33:50.854886Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:34:01.524561Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:34:01.527141Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/68a0d3c9933f2c12ebb1ef5f7bb263cdc58c1ba1e7ef2eb79fb0fe86a955f06b/merged/disk/downloaded to root: /var/lib/kubelet/pods/36c497ea-f28a-4b43-8082-19d493e975ac/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:34:01.527474Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:34:01.563645Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:34:01.563741Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:34:01.577035Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:34:01.603567Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 69578","pos":"common.go:390","timestamp":"2023-01-16T11:34:01.603661Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:34:01.603951Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:34:01.613205Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:34:01.613282Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:34:01.613379Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:34:01.613490Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:34:01.613537Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:34:01.613575Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:34:01.624298Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:34:01.624561Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid b1927206-3520-473a-af59-627b2f709681","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:34:01.624708Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:34:01.624782Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/36c497ea-f28a-4b43-8082-19d493e975ac/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:34:01.624837Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/36c497ea-f28a-4b43-8082-19d493e975ac/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:34:01.625041Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:34:01.646482Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:34:01.648059Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:34:01.648275Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:34:01.648111Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid b1927206-3520-473a-af59-627b2f709681","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:34:01.649737Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:34:01.649818Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:34:01.649841Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:34:01.650009Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:34:01.708351Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid b1927206-3520-473a-af59-627b2f709681","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:34:01.708406Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:34:01.718910Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:34:01.718957Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:34:01.719123Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:34:01.760537Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid b1927206-3520-473a-af59-627b2f709681","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:34:01.760639Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:34:01.760704Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:34:01.760733Z","uid":"b1927206-3520-473a-af59-627b2f709681"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:34:01.760810Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:34:05.673156Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:34:05.673192Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:34:05.673214Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:36:00.626836Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:39:01.758070Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net335],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:39:01.758207Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:39:01.758791Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm746],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:39:01.759080Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:39:01.761550Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun305],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:39:01.761660Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:39:13.765809Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:39:13.767985Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/36c695098e747a07b64fefaa2dcadcbd8f544ceff49a45e754f5fc00cffd7469/merged/disk/downloaded to root: /var/lib/kubelet/pods/f141b652-7c8a-47a3-822e-bdf956dcf658/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:39:13.768162Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:39:13.801290Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:39:13.801365Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:39:13.815087Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:39:13.839111Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 74489","pos":"common.go:390","timestamp":"2023-01-16T11:39:13.839183Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:39:13.839475Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:39:13.847143Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:39:13.847171Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:39:13.847218Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:39:13.847282Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:39:13.847294Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:39:13.847311Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:39:13.858085Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:39:13.858671Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 471cb64a-0f1a-4f70-97ad-8dc103f269cb","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:39:13.860800Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:39:13.861042Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/f141b652-7c8a-47a3-822e-bdf956dcf658/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:39:13.861067Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/f141b652-7c8a-47a3-822e-bdf956dcf658/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:39:13.861832Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:39:13.890014Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:39:13.891010Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:39:13.895254Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:39:13.895522Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 471cb64a-0f1a-4f70-97ad-8dc103f269cb","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:39:13.895666Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:39:13.895749Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:39:13.895765Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:39:13.895903Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:39:13.903308Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 471cb64a-0f1a-4f70-97ad-8dc103f269cb","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:39:13.904273Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:39:13.904362Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:39:13.904420Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:39:13.904496Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:39:13.916285Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 471cb64a-0f1a-4f70-97ad-8dc103f269cb","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:39:13.916741Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:39:13.916844Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:39:13.916900Z","uid":"471cb64a-0f1a-4f70-97ad-8dc103f269cb"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:39:13.917012Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:39:17.913757Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:39:17.913808Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:39:17.913851Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:41:00.627302Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:44:14.007654Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net784],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:44:14.008777Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:44:14.009627Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm602],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:44:14.009663Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:44:14.010168Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun736],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:44:14.010196Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:44:26.036885Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:44:26.038732Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/ce2c60221fce42d6802d4da2466bfcfb4c2abe6407b473c9484e5df543339cfc/merged/disk/downloaded to root: /var/lib/kubelet/pods/e61ac7ba-1d20-4340-9d25-d92c6f1958ce/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:44:26.039009Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:44:26.073760Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:44:26.073802Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:44:26.087066Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:44:26.117596Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 79581","pos":"common.go:390","timestamp":"2023-01-16T11:44:26.117640Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:44:26.118037Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:44:26.126279Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:44:26.126316Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:44:26.126453Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:44:26.126900Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:44:26.126928Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:44:26.126957Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:44:26.136398Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:44:26.137247Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 12d3bafd-8e6a-40e6-a74c-86d5c8682424","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:44:26.137367Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:44:26.137505Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/e61ac7ba-1d20-4340-9d25-d92c6f1958ce/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:44:26.137547Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/e61ac7ba-1d20-4340-9d25-d92c6f1958ce/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:44:26.140999Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:44:26.206416Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:44:26.206720Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:44:26.206858Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 12d3bafd-8e6a-40e6-a74c-86d5c8682424","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:44:26.206960Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:44:26.207205Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:44:26.207247Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:44:26.207399Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:44:26.206854Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:44:26.211300Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 12d3bafd-8e6a-40e6-a74c-86d5c8682424","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:44:26.211485Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:44:26.211597Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:44:26.211643Z","uid":"12d3bafd-8e6a-40e6-a74c-86d5c8682424"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:44:26.211794Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:44:30.151590Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:44:30.151626Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:44:30.151648Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:46:00.626955Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:49:26.230069Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net840],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:49:26.230828Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:49:26.231807Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm840],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:49:26.231904Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:49:26.234954Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun388],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:49:26.235074Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:49:36.278310Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:49:36.280831Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/82ab71b8944719eb56302face1bebd52e7acf6fcc901112acd8437a6647eefdf/merged/disk/downloaded to root: /var/lib/kubelet/pods/37570081-802f-49dc-914b-28cca98d8d76/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:49:36.281086Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:49:36.319634Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:49:36.319700Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:49:36.335636Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:49:36.367678Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 84526","pos":"common.go:390","timestamp":"2023-01-16T11:49:36.367733Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:49:36.368061Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:49:36.376601Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:49:36.376637Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:49:36.376709Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:49:36.376811Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:49:36.376840Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:49:36.376895Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:49:36.388432Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:49:36.388635Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid ca29bf3e-8670-4712-900a-0944763a4ac5","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:49:36.388759Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:49:36.388850Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/37570081-802f-49dc-914b-28cca98d8d76/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:49:36.388932Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/37570081-802f-49dc-914b-28cca98d8d76/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:49:36.389092Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:49:36.458645Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:49:36.458759Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:49:36.458792Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid ca29bf3e-8670-4712-900a-0944763a4ac5","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:49:36.458809Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:49:36.458993Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:49:36.460288Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:49:36.460314Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:49:36.460375Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:49:36.464263Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid ca29bf3e-8670-4712-900a-0944763a4ac5","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:49:36.464424Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:49:36.464515Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:49:36.464595Z","uid":"ca29bf3e-8670-4712-900a-0944763a4ac5"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:49:36.464695Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:49:40.421008Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:49:40.421044Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:49:40.421065Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:51:00.626318Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:54:36.492129Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm918],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:54:36.492178Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:54:36.492931Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun769],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:54:36.492963Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:54:36.493538Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net317],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:54:36.493565Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:54:46.498658Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:54:46.501188Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/f91c1925a5f8f5c6450af4e2a3e629814f9d8709f7a54f81acca90ef85e0d2fd/merged/disk/downloaded to root: /var/lib/kubelet/pods/9ddbb02d-e41c-4403-b663-a4bb9199aed6/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:54:46.501445Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:54:46.533031Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:54:46.533188Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:54:46.546718Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:54:46.572469Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 89594","pos":"common.go:390","timestamp":"2023-01-16T11:54:46.572618Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:54:46.573134Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:54:46.580126Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:54:46.580154Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:54:46.580204Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:54:46.580270Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:54:46.580282Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:54:46.580300Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:54:46.590858Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:54:46.595935Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 446215cc-e598-4f44-8f9a-9b42012139a0","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:54:46.596754Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:54:46.596809Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/9ddbb02d-e41c-4403-b663-a4bb9199aed6/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:54:46.596827Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/9ddbb02d-e41c-4403-b663-a4bb9199aed6/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:54:46.596972Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:54:46.634313Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:54:46.634500Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:54:46.634649Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:54:46.634703Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 446215cc-e598-4f44-8f9a-9b42012139a0","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:54:46.634746Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:54:46.634784Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:54:46.634836Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:54:46.634890Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:54:46.645889Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 446215cc-e598-4f44-8f9a-9b42012139a0","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:54:46.646145Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:54:46.646241Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:54:46.646271Z","uid":"446215cc-e598-4f44-8f9a-9b42012139a0"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:54:46.646370Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T11:54:50.638411Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:54:50.638449Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:54:50.638470Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T11:56:00.626798Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T11:59:46.686094Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm92],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:59:46.687000Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T11:59:46.687632Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun688],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:59:46.687691Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T11:59:46.688335Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net296],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T11:59:46.688381Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:59:55.944060Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T11:59:55.946970Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/397678e7b48525891141793ff72d03aec381721e7ccd162b76401a1ad7169866/merged/disk/downloaded to root: /var/lib/kubelet/pods/3caf0925-f618-40e1-bdbf-47efa840c0b7/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T11:59:55.947153Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T11:59:55.979131Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T11:59:55.979301Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T11:59:55.993317Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T11:59:56.040776Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 94484","pos":"common.go:390","timestamp":"2023-01-16T11:59:56.041007Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T11:59:56.041463Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:59:56.058461Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T11:59:56.058525Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:59:56.058617Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:59:56.058729Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T11:59:56.058771Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T11:59:56.058806Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T11:59:56.081299Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:59:56.081601Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 2e960e63-2d8c-4d3f-a5c6-80ec1b617c40","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:59:56.081798Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T11:59:56.082005Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/3caf0925-f618-40e1-bdbf-47efa840c0b7/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T11:59:56.082137Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/3caf0925-f618-40e1-bdbf-47efa840c0b7/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T11:59:56.082465Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:59:56.138246Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:59:56.140939Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:59:56.142473Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 2e960e63-2d8c-4d3f-a5c6-80ec1b617c40","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:59:56.142761Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:59:56.143346Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:59:56.143547Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:59:56.144191Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T11:59:56.141781Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:59:56.190540Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 2e960e63-2d8c-4d3f-a5c6-80ec1b617c40","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:59:56.191172Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:59:56.191401Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:59:56.191548Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:59:56.191780Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T11:59:56.236152Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 2e960e63-2d8c-4d3f-a5c6-80ec1b617c40","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T11:59:56.236914Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T11:59:56.237115Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T11:59:56.237231Z","uid":"2e960e63-2d8c-4d3f-a5c6-80ec1b617c40"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T11:59:56.237398Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T12:00:00.079907Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:00:00.079995Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:00:00.080022Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T12:01:00.626853Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T12:04:56.155416Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm234],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:04:56.156515Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T12:04:56.157194Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun758],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:04:56.158216Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T12:04:56.158917Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net101],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:04:56.158995Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:05:06.339811Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T12:05:06.348580Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/42321b039598eb0cabf65af88474b6192493bc7ade00d992c139c5f84adb2164/merged/disk/downloaded to root: /var/lib/kubelet/pods/e58aa8cc-864e-400e-8779-f903f601de1f/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T12:05:06.350227Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T12:05:06.490614Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T12:05:06.491138Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T12:05:06.556273Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T12:05:06.662123Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 99462","pos":"common.go:390","timestamp":"2023-01-16T12:05:06.662503Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T12:05:06.663748Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T12:05:06.706545Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T12:05:06.706668Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T12:05:06.706843Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T12:05:06.707459Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T12:05:06.707561Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T12:05:06.707636Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T12:05:06.775308Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:05:06.780923Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid de044d02-77a3-4d20-9d18-89e0df08efc8","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:05:06.786258Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T12:05:06.786942Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/e58aa8cc-864e-400e-8779-f903f601de1f/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T12:05:06.787137Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/e58aa8cc-864e-400e-8779-f903f601de1f/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T12:05:06.788340Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:05:07.012464Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:05:07.012904Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:05:07.013031Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid de044d02-77a3-4d20-9d18-89e0df08efc8","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:05:07.013133Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T12:05:07.013811Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:05:07.033722Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:05:07.033849Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:05:07.034400Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:05:07.106642Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid de044d02-77a3-4d20-9d18-89e0df08efc8","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:05:07.115660Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:05:07.121106Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:05:07.121853Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:05:07.127640Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:05:07.208285Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid de044d02-77a3-4d20-9d18-89e0df08efc8","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:05:07.209181Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:05:07.209744Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:05:07.210277Z","uid":"de044d02-77a3-4d20-9d18-89e0df08efc8"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:05:07.210914Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T12:05:12.583458Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:05:12.583621Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:05:12.583730Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T12:06:00.627851Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T12:10:06.671111Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm39],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:10:06.671823Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T12:10:06.672400Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun906],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:10:06.672429Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T12:10:06.674655Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net193],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:10:06.674699Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:10:16.645236Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T12:10:16.648415Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/4a6642b7cb04e21ee091681ea28454a8f6baf51d3fce726ea0103a5327cee6ab/merged/disk/downloaded to root: /var/lib/kubelet/pods/f8917028-50e5-4a6e-b739-a91e388320ac/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T12:10:16.648800Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T12:10:16.679056Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T12:10:16.679094Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T12:10:16.692195Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T12:10:16.715761Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 104539","pos":"common.go:390","timestamp":"2023-01-16T12:10:16.715801Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T12:10:16.716200Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T12:10:16.724414Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T12:10:16.724454Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T12:10:16.724581Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T12:10:16.724670Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T12:10:16.725061Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T12:10:16.725094Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T12:10:16.734625Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:10:16.734665Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 04dd1f8e-025a-4c37-8a96-5db005f22423","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:10:16.734701Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T12:10:16.735113Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/f8917028-50e5-4a6e-b739-a91e388320ac/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T12:10:16.735134Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/f8917028-50e5-4a6e-b739-a91e388320ac/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T12:10:16.735322Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:10:16.777007Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:10:16.777648Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T12:10:16.777756Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:10:16.777690Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 04dd1f8e-025a-4c37-8a96-5db005f22423","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:10:16.777943Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:10:16.777972Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:10:16.777996Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:10:16.778065Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:10:16.779179Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 04dd1f8e-025a-4c37-8a96-5db005f22423","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:10:16.779211Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:10:16.779285Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:10:16.779301Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:10:16.779381Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:10:16.792572Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 04dd1f8e-025a-4c37-8a96-5db005f22423","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:10:16.794905Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:10:16.795063Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:10:16.795098Z","uid":"04dd1f8e-025a-4c37-8a96-5db005f22423"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:10:16.795179Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T12:10:21.015196Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:10:21.015236Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:10:21.015260Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T12:11:00.626975Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T12:15:16.118026Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm563],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:15:16.118078Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T12:15:16.119037Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun878],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:15:16.119152Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T12:15:16.119697Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net243],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:15:16.119738Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:15:26.145387Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T12:15:26.148268Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/539c2efd4f57a4737baa1ee5735291241135cdbe32f16349dfad6fa2c5b89e4d/merged/disk/downloaded to root: /var/lib/kubelet/pods/1fee86f4-c7d1-4320-8a1d-26d644255b28/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T12:15:26.148585Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T12:15:26.180540Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T12:15:26.180704Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T12:15:26.194080Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T12:15:26.219420Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 109453","pos":"common.go:390","timestamp":"2023-01-16T12:15:26.219581Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T12:15:26.219844Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T12:15:26.227719Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T12:15:26.227789Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T12:15:26.227895Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T12:15:26.228276Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T12:15:26.230695Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T12:15:26.230787Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T12:15:26.238982Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:15:26.239114Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 161274ab-1851-41ae-ad87-53fb4231481f","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:15:26.239213Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T12:15:26.239285Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/1fee86f4-c7d1-4320-8a1d-26d644255b28/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T12:15:26.239444Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/1fee86f4-c7d1-4320-8a1d-26d644255b28/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T12:15:26.241988Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:15:26.283583Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:15:26.283910Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T12:15:26.284105Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:15:26.284251Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 161274ab-1851-41ae-ad87-53fb4231481f","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:15:26.284302Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:15:26.284368Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:15:26.284405Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:15:26.284458Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:15:26.293942Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 161274ab-1851-41ae-ad87-53fb4231481f","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:15:26.294382Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:15:26.294452Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:15:26.294507Z","uid":"161274ab-1851-41ae-ad87-53fb4231481f"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:15:26.294584Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T12:15:30.196015Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:15:30.196053Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:15:30.196087Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T12:16:00.627010Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T12:20:26.272719Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net489],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:20:26.272909Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T12:20:26.275129Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm148],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:20:26.275289Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T12:20:26.275962Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun857],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:20:26.276053Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:20:37.296475Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T12:20:37.300998Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/f57841bf3479da66af7746d04a123c1b9214838047fc9c58fe30aadc5899b7f7/merged/disk/downloaded to root: /var/lib/kubelet/pods/bcced692-5878-4afd-8a52-b7455b2d0c16/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T12:20:37.301237Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T12:20:37.339691Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T12:20:37.339782Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T12:20:37.354886Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T12:20:37.378884Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 114425","pos":"common.go:390","timestamp":"2023-01-16T12:20:37.378957Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T12:20:37.379288Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T12:20:37.387001Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T12:20:37.387035Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T12:20:37.387081Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T12:20:37.387148Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T12:20:37.387163Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T12:20:37.387183Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T12:20:37.398773Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:20:37.398814Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid bda0a31f-1c96-41ec-ad63-e8bee7cb4a08","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:20:37.404196Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T12:20:37.404243Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/bcced692-5878-4afd-8a52-b7455b2d0c16/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T12:20:37.404321Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/bcced692-5878-4afd-8a52-b7455b2d0c16/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T12:20:37.404518Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:20:37.446955Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:20:37.447180Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:20:37.447259Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid bda0a31f-1c96-41ec-ad63-e8bee7cb4a08","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:20:37.447351Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T12:20:37.447393Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:20:37.447416Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:20:37.447964Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:20:37.448049Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:20:37.458317Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid bda0a31f-1c96-41ec-ad63-e8bee7cb4a08","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:20:37.458561Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:20:37.458623Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:20:37.458659Z","uid":"bda0a31f-1c96-41ec-ad63-e8bee7cb4a08"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:20:37.458729Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T12:20:41.446411Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:20:41.446451Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:20:41.446480Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T12:21:00.626335Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:247","timestamp":"2023-01-16T12:25:37.520275Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[tun416],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:25:37.520355Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:247","timestamp":"2023-01-16T12:25:37.521004Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[vhost-net470],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:25:37.521035Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:247","timestamp":"2023-01-16T12:25:37.521564Z"}
{"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [\u0026ContainerAllocateRequest{DevicesIDs:[kvm93],}]","pos":"generic_device.go:248","timestamp":"2023-01-16T12:25:37.521588Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:25:50.530426Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","level":"info","msg":"found 2 possible mount point candidates for path /","pos":"isolation.go:193","timestamp":"2023-01-16T12:25:50.534594Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /var/lib/docker/overlay2/dc60d9222a01d5d6de39d5f34c72ca044af7bc2541ebe1acab637773d0bf499c/merged/disk/downloaded to root: /var/lib/kubelet/pods/d76b71ba-8e38-43b7-bca6-df1327a2debf/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:307","timestamp":"2023-01-16T12:25:50.534853Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"testvm","namespace":"kubevirt","pos":"mount.go:405","timestamp":"2023-01-16T12:25:50.569130Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"testvm","namespace":"kubevirt","pos":"mount.go:408","timestamp":"2023-01-16T12:25:50.569203Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2023-01-16T12:25:50.583331Z"}
{"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2023-01-16T12:25:50.607481Z"}
{"component":"virt-handler","level":"info","msg":"Created tap device: tap0 in PID: 119502","pos":"common.go:390","timestamp":"2023-01-16T12:25:50.607548Z"}
{"component":"virt-handler","level":"info","msg":"Successfully configured tap device: tap0","pos":"common.go:429","timestamp":"2023-01-16T12:25:50.607757Z"}
{"component":"virt-handler","level":"error","msg":"failed to create ipv4 nat rules for vm error: Couldn't configure ip nat rules","pos":"masquerade.go:146","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T12:25:50.615121Z"}
{"component":"virt-handler","level":"error","msg":"failed to prepare pod networking","pos":"podnic.go:230","reason":"Couldn't configure ip nat rules","timestamp":"2023-01-16T12:25:50.615225Z"}
{"component":"virt-handler","kind":"","level":"error","msg":"Synchronizing the VirtualMachineInstance failed.","name":"testvm","namespace":"kubevirt","pos":"vm.go:1781","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T12:25:50.615309Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T12:25:50.615414Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"testvm","namespace":"kubevirt","pos":"vm.go:2300","timestamp":"2023-01-16T12:25:50.615461Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","level":"error","msg":"virt-launcher crashed due to a network error. Updating VMI testvm status to Failed","pos":"vm.go:1216","timestamp":"2023-01-16T12:25:50.615508Z"}
{"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance kubevirt/testvm","pos":"vm.go:1433","reason":"failed to configure vmi network: setup failed, err: failed plugging phase1 at nic 'eth0': Critical network error: Couldn't configure ip nat rules","timestamp":"2023-01-16T12:25:50.626875Z"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:25:50.627132Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 6302788e-bbb0-4fbb-a81f-ccd217c1626b","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:25:50.627280Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"Found container disk mount entries","name":"testvm","namespace":"kubevirt","pos":"mount.go:353","timestamp":"2023-01-16T12:25:50.627345Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"Looking to see if containerdisk is mounted at path /var/lib/kubelet/pods/d76b71ba-8e38-43b7-bca6-df1327a2debf/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:355","timestamp":"2023-01-16T12:25:50.627368Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"unmounting container disk at path root: /, relative: /var/lib/kubelet/pods/d76b71ba-8e38-43b7-bca6-df1327a2debf/volumes/kubernetes.io~empty-dir/container-disks/disk_0.img","name":"testvm","namespace":"kubevirt","pos":"mount.go:367","timestamp":"2023-01-16T12:25:50.627529Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:25:50.647057Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:25:50.647264Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"closing notify pipe listener for vmi","name":"testvm","namespace":"kubevirt","pos":"vm.go:318","timestamp":"2023-01-16T12:25:50.648117Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:25:50.648325Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 6302788e-bbb0-4fbb-a81f-ccd217c1626b","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:25:50.648431Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:25:50.648492Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:25:50.648510Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:25:50.648703Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:25:50.670152Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 6302788e-bbb0-4fbb-a81f-ccd217c1626b","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:25:50.670295Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:25:50.670350Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:25:50.670366Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:25:50.670457Z","uid":""}
{"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Failed | Domain does not exist","name":"testvm","namespace":"kubevirt","pos":"vm.go:1643","timestamp":"2023-01-16T12:25:50.686929Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"Performing final local cleanup for vmi with uid 6302788e-bbb0-4fbb-a81f-ccd217c1626b","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:25:50.687053Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"No container disk mount entries found to unmount","name":"testvm","namespace":"kubevirt","pos":"mount.go:349","timestamp":"2023-01-16T12:25:50.687160Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"","level":"info","msg":"Cleaning up remaining hotplug volumes","name":"testvm","namespace":"kubevirt","pos":"mount.go:770","timestamp":"2023-01-16T12:25:50.687233Z","uid":"6302788e-bbb0-4fbb-a81f-ccd217c1626b"}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:25:50.687326Z","uid":""}
{"component":"virt-handler","level":"info","msg":"VMI does not exist | Domain does not exist","pos":"vm.go:1648","timestamp":"2023-01-16T12:25:54.678818Z"}
{"component":"virt-handler","kind":"VirtualMachineInstance","level":"info","msg":"Performing final local cleanup for vmi with uid ","name":"testvm","namespace":"kubevirt","pos":"vm.go:1899","timestamp":"2023-01-16T12:25:54.678854Z","uid":""}
{"component":"virt-handler","kind":"Domain","level":"info","msg":"Removing domain from cache during final cleanup","name":"testvm","namespace":"kubevirt","pos":"vm.go:1933","timestamp":"2023-01-16T12:25:54.682372Z","uid":""}
{"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"cache.go:385","timestamp":"2023-01-16T12:26:00.626564Z"}