The virtual machine takes 4 minutes to start up.

[Meteor Cai]

I used the Ubuntu 22.04 image to create the VMI. It took over 4 minutes from the creation process until the virtual machine could be connected via IP.  

After logging into the virtual machine via SSH, and then using the "system-analyze" command to view the results, it was found that the system startup only took 24 seconds. The first timestamp in the dmesg log is: 09:22:30, and the last one is: 09:22:53. It seems to be consistent.

The log related to virt-handler is as follows: 

2025-11-28T09:18:25.589552135+08:00 stderr F {"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: vhost-net","pos":"generic_device.go:240","timestamp":"2025-11-28T01:18:25.589467Z"}
2025-11-28T09:18:25.589565936+08:00 stderr F {"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [&ContainerAllocateRequest{DevicesIDs:[vhost-net771],}]","pos":"generic_device.go:241","timestamp":"2025-11-28T01:18:25.589500Z"}
2025-11-28T09:18:25.590035433+08:00 stderr F {"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: kvm","pos":"generic_device.go:240","timestamp":"2025-11-28T01:18:25.589991Z"}
2025-11-28T09:18:25.590041828+08:00 stderr F {"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [&ContainerAllocateRequest{DevicesIDs:[kvm454],}]","pos":"generic_device.go:241","timestamp":"2025-11-28T01:18:25.590008Z"}
2025-11-28T09:18:25.590693343+08:00 stderr F {"component":"virt-handler","level":"info","msg":"Generic Allocate: resourceName: tun","pos":"generic_device.go:240","timestamp":"2025-11-28T01:18:25.590660Z"}
2025-11-28T09:18:25.590707347+08:00 stderr F {"component":"virt-handler","level":"info","msg":"Generic Allocate: request: [&ContainerAllocateRequest{DevicesIDs:[tun936],}]","pos":"generic_device.go:241","timestamp":"2025-11-28T01:18:25.590679Z"}
2025-11-28T09:18:31.711162849+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain does not exist","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:1901","timestamp":"2025-11-28T01:18:31.710851Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:31.714720898+08:00 stderr F {"component":"virt-handler","level":"info","msg":"initialized a new cgroup v1 manager successfully. controllerPaths: map[:/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope blkio:/blkio/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpu:/cpu/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpuacct:/cpuacct/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpuset:/cpuset/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope devices:/devices/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope freezer:/freezer/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope hugetlb:/hugetlb/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope memory:/memory/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope name=systemd:/name=systemd/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope net_cls:/net_cls/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope net_prio:/net_prio/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope perf_event:/perf_event/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope pids:/pids/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope rdma:/rdma/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope], procCgroupBasePath: /proc/774138/cgroup","pos":"cgroup.go:135","timestamp":"2025-11-28T01:18:31.714536Z"}
2025-11-28T09:18:31.71812217+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"Bind mounting container disk at root: /proc/1/root, relative: /run/containerd/io.containerd.runtime.v2.task/k8s.io/6e9e8036abc4a1a3bf537b18949b70f8a1203d5bd2574e21fbd92599d52c857e/rootfs/disk/ubuntu-22.04-compressed-0711.qcow2 to root: /var/lib/kubelet/pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/container-disks, relative: /disk_0.img","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"mount.go:289","timestamp":"2025-11-28T01:18:31.717972Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:31.795459859+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"mounting kernel artifacts","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"mount.go:407","timestamp":"2025-11-28T01:18:31.795093Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:31.79552187+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"kernel boot not defined - nothing to mount","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"mount.go:410","timestamp":"2025-11-28T01:18:31.795212Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:31.800237404+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"Current pod network: {\"interfaces\":[{\"name\":\"lo\",\"index\":1,\"type\":\"device\",\"state\":\"unknown\",\"mtu\":65536,\"ethtool\":{\"feature\":{\"tx-checksum\":true}},\"IPv4\":{\"enabled\":true,\"address\":[{\"IP\":\"127.0.0.1\",\"prefix-length\":8}]},\"IPv6\":{\"enabled\":true,\"address\":[{\"IP\":\"::1\",\"prefix-length\":128}]},\"linux-stack\":{\"ip4-route-local-net\":false,\"port-learning\":false},\"Metadata\":null},{\"name\":\"tunl0\",\"index\":2,\"type\":\"ipip\",\"state\":\"down\",\"mtu\":1480,\"ethtool\":{\"feature\":{\"tx-checksum\":true}},\"IPv4\":{\"enabled\":false},\"IPv6\":{\"enabled\":false},\"linux-stack\":{\"ip4-route-local-net\":false,\"port-learning\":false},\"Metadata\":null},{\"name\":\"eth0\",\"index\":4,\"type\":\"veth\",\"state\":\"up\",\"mac-address\":\"2a:ab:d7:32:60:d9\",\"mtu\":1480,\"ethtool\":{\"feature\":{\"tx-checksum\":true}},\"IPv4\":{\"enabled\":true,\"address\":[{\"IP\":\"172.22.59.198\",\"prefix-length\":32}]},\"IPv6\":{\"enabled\":true,\"address\":[{\"IP\":\"fe80::28ab:d7ff:fe32:60d9\",\"prefix-length\":64}]},\"linux-stack\":{\"ip4-route-local-net\":false,\"port-learning\":false},\"Metadata\":null}],\"routes\":{\"running\":[{\"destination\":\"0.0.0.0/0\",\"next-hop-interface\":\"eth0\",\"next-hop-address\":\"169.254.1.1\",\"table-id\":254},{\"destination\":\"169.254.1.1/32\",\"next-hop-interface\":\"eth0\",\"table-id\":254},{\"destination\":\"fe80::/64\",\"next-hop-interface\":\"eth0\",\"table-id\":254}]},\"linux-stack\":{\"ipv4\":{\"arp-ignore\":0,\"forwarding\":false,\"ping-group-range\":[1,0],\"unprivileged-port-start\":1024},\"ipv6\":{\"forwarding\":false}}}","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"netpod.go:185","timestamp":"2025-11-28T01:18:31.799935Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:31.801683521+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"Desired pod network: {\"interfaces\":[{\"name\":\"k6t-eth0\",\"type\":\"bridge\",\"state\":\"up\",\"ethtool\":{\"feature\":{\"tx-checksum\":false}},\"IPv4\":{\"enabled\":true,\"address\":[{\"IP\":\"169.254.75.10\",\"prefix-length\":32}]},\"IPv6\":{},\"linux-stack\":{},\"Metadata\":{\"Pid\":0,\"NetworkName\":\"default\"}},{\"name\":\"eth0-nic\",\"index\":4,\"state\":\"up\",\"copy-mac-from\":\"k6t-eth0\",\"controller\":\"k6t-eth0\",\"ethtool\":{\"feature\":{}},\"IPv4\":{\"enabled\":false},\"IPv6\":{\"enabled\":false},\"linux-stack\":{\"port-learning\":false},\"Metadata\":{\"Pid\":0,\"NetworkName\":\"default\"}},{\"name\":\"tap0\",\"type\":\"tap\",\"state\":\"up\",\"mtu\":1480,\"controller\":\"k6t-eth0\",\"ethtool\":{\"feature\":{}},\"tap\":{\"UID\":107,\"GID\":107},\"IPv4\":{},\"IPv6\":{},\"linux-stack\":{},\"Metadata\":{\"Pid\":774138,\"NetworkName\":\"default\"}},{\"name\":\"eth0\",\"type\":\"dummy\",\"mac-address\":\"2a:ab:d7:32:60:d9\",\"mtu\":1480,\"ethtool\":{\"feature\":{}},\"IPv4\":{\"enabled\":true,\"address\":[{\"IP\":\"172.22.59.198\",\"prefix-length\":32}]},\"IPv6\":{\"enabled\":true,\"address\":[{\"IP\":\"fe80::28ab:d7ff:fe32:60d9\",\"prefix-length\":64}]},\"linux-stack\":{},\"Metadata\":{\"Pid\":0,\"NetworkName\":\"default\"}}],\"linux-stack\":{\"ipv4\":{\"arp-ignore\":1},\"ipv6\":{}}}","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"netpod.go:242","timestamp":"2025-11-28T01:18:31.801442Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:31.841444473+08:00 stderr F {"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Executing... Switching from original () to desired () context","pos":"context_executor.go:75","timestamp":"2025-11-28T01:18:31.841166Z"}
2025-11-28T09:18:31.856964988+08:00 stderr F {"component":"virt-handler","level":"info","msg":"[ContextExecutor]: Execution ended successfully","pos":"context_executor.go:90","timestamp":"2025-11-28T01:18:31.856722Z"}
2025-11-28T09:18:33.115536231+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"Accepted new notify pipe connection for vmi","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:398","timestamp":"2025-11-28T01:18:33.115445Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:33.116839001+08:00 stderr F {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain is in state Shutoff reason Unknown","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:3362","timestamp":"2025-11-28T01:18:33.116773Z","uid":""}
2025-11-28T09:18:42.58306798+08:00 stderr F {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain is in state Paused reason StartingUp","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:3392","timestamp":"2025-11-28T01:18:42.582935Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:42.825164066+08:00 stderr F {"component":"virt-handler","kind":"Domain","level":"info","msg":"Domain is in state Running reason Unknown","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:3392","timestamp":"2025-11-28T01:18:42.825111Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:42.826718019+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of containerdisk volume","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:2545","timestamp":"2025-11-28T01:18:42.826669Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:42.82672705+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of cloudinitdisk volume","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:2545","timestamp":"2025-11-28T01:18:42.826700Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:42.826728263+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"migration is block migration because of kubeconfig volume","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:2545","timestamp":"2025-11-28T01:18:42.826712Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:43.785110344+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Scheduled | Domain status: Running, reason: Unknown","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:1899","timestamp":"2025-11-28T01:18:43.785007Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:43.80899226+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running | Domain status: Running, reason: Unknown","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:1899","timestamp":"2025-11-28T01:18:43.808953Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:43.809123187+08:00 stderr F {"component":"virt-handler","level":"info","msg":"initialized a new cgroup v1 manager successfully. controllerPaths: map[:/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope blkio:/blkio/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpu:/cpu/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpuacct:/cpuacct/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpuset:/cpuset/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope devices:/devices/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope freezer:/freezer/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope hugetlb:/hugetlb/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope memory:/memory/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope name=systemd:/name=systemd/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope net_cls:/net_cls/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope net_prio:/net_prio/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope perf_event:/perf_event/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope pids:/pids/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope rdma:/rdma/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope], procCgroupBasePath: /proc/774138/cgroup","pos":"cgroup.go:135","timestamp":"2025-11-28T01:18:43.809100Z"}
2025-11-28T09:18:43.839658631+08:00 stderr F {"component":"virt-handler","kind":"","level":"error","msg":"Updating the VirtualMachineInstance status failed.","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:2059","reason":"Operation cannot be fulfilled on virtualmachineinstances.kubevirt.io \"kubevirt-1l600-test\": the object has been modified; please apply your changes to the latest version and try again","timestamp":"2025-11-28T01:18:43.839547Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:43.839670422+08:00 stderr F {"component":"virt-handler","level":"info","msg":"re-enqueuing VirtualMachineInstance cideploy/kubevirt-1l600-test","pos":"vm.go:1714","reason":"Operation cannot be fulfilled on virtualmachineinstances.kubevirt.io \"kubevirt-1l600-test\": the object has been modified; please apply your changes to the latest version and try again","timestamp":"2025-11-28T01:18:43.839570Z"}
2025-11-28T09:18:43.83967229+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running | Domain status: Running, reason: Unknown","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:1899","timestamp":"2025-11-28T01:18:43.839583Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:43.839768021+08:00 stderr F {"component":"virt-handler","level":"info","msg":"initialized a new cgroup v1 manager successfully. controllerPaths: map[:/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope blkio:/blkio/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpu:/cpu/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpuacct:/cpuacct/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpuset:/cpuset/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope devices:/devices/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope freezer:/freezer/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope hugetlb:/hugetlb/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope memory:/memory/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope name=systemd:/name=systemd/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope net_cls:/net_cls/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope net_prio:/net_prio/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope perf_event:/perf_event/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope pids:/pids/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope rdma:/rdma/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope], procCgroupBasePath: /proc/774138/cgroup","pos":"cgroup.go:135","timestamp":"2025-11-28T01:18:43.839711Z"}
2025-11-28T09:18:43.884322075+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running | Domain status: Running, reason: Unknown","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:1899","timestamp":"2025-11-28T01:18:43.884161Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:18:43.884441368+08:00 stderr F {"component":"virt-handler","level":"info","msg":"initialized a new cgroup v1 manager successfully. controllerPaths: map[:/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope blkio:/blkio/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpu:/cpu/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpuacct:/cpuacct/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpuset:/cpuset/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope devices:/devices/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope freezer:/freezer/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope hugetlb:/hugetlb/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope memory:/memory/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope name=systemd:/name=systemd/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope net_cls:/net_cls/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope net_prio:/net_prio/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope perf_event:/perf_event/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope pids:/pids/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope rdma:/rdma/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope], procCgroupBasePath: /proc/774138/cgroup","pos":"cgroup.go:135","timestamp":"2025-11-28T01:18:43.884380Z"}
2025-11-28T09:18:51.782970328+08:00 stderr F {"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:350","timestamp":"2025-11-28T01:18:51.782856Z"}
2025-11-28T09:18:51.782992174+08:00 stderr F {"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:351","timestamp":"2025-11-28T01:18:51.782896Z"}
2025-11-28T09:18:51.782995501+08:00 stderr F {"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:352","timestamp":"2025-11-28T01:18:51.782903Z"}
2025-11-28T09:19:24.607698455+08:00 stderr F {"component":"virt-handler","level":"error","msg":"failed to scrape metrics from //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock","pos":"scrapper.go:48","reason":"failed to update domain stats from socket //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock: unknown error encountered sending command GetDomainStats: rpc error: code = DeadlineExceeded desc = context deadline exceeded","timestamp":"2025-11-28T01:19:24.607543Z"}
2025-11-28T09:19:52.607567217+08:00 stderr F {"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:350","timestamp":"2025-11-28T01:19:52.607436Z"}
2025-11-28T09:19:52.607588988+08:00 stderr F {"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:351","timestamp":"2025-11-28T01:19:52.607476Z"}
2025-11-28T09:19:52.607591793+08:00 stderr F {"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:352","timestamp":"2025-11-28T01:19:52.607484Z"}
2025-11-28T09:20:14.163688943+08:00 stderr F {"component":"virt-handler","level":"error","msg":"failed to scrape metrics from //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock","pos":"scrapper.go:48","reason":"failed to update domain stats from socket //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock: unknown error encountered sending command GetDomainStats: rpc error: code = DeadlineExceeded desc = context deadline exceeded","timestamp":"2025-11-28T01:20:14.163519Z"}
2025-11-28T09:20:25.060088908+08:00 stderr F {"component":"virt-handler","level":"error","msg":"failed to scrape metrics from //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock","pos":"scrapper.go:48","reason":"failed to update domain stats from socket //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock: unknown error encountered sending command GetDomainStats: rpc error: code = DeadlineExceeded desc = context deadline exceeded","timestamp":"2025-11-28T01:20:25.059863Z"}
2025-11-28T09:20:44.391725229+08:00 stderr F {"component":"virt-handler","level":"error","msg":"failed to scrape metrics from //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock","pos":"scrapper.go:48","reason":"failed to update domain stats from socket //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock: unknown error encountered sending command GetDomainStats: rpc error: code = DeadlineExceeded desc = context deadline exceeded","timestamp":"2025-11-28T01:20:44.391507Z"}
2025-11-28T09:21:07.054223327+08:00 stderr F {"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:350","timestamp":"2025-11-28T01:21:07.052037Z"}
2025-11-28T09:21:07.054271095+08:00 stderr F {"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:351","timestamp":"2025-11-28T01:21:07.052077Z"}
2025-11-28T09:21:07.05427637+08:00 stderr F {"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:352","timestamp":"2025-11-28T01:21:07.052087Z"}
2025-11-28T09:21:13.899206395+08:00 stderr F {"component":"virt-handler","level":"error","msg":"failed to scrape metrics from //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock","pos":"scrapper.go:48","reason":"failed to update domain stats from socket //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock: unknown error encountered sending command GetDomainStats: rpc error: code = DeadlineExceeded desc = context deadline exceeded","timestamp":"2025-11-28T01:21:13.899030Z"}
2025-11-28T09:21:44.030209856+08:00 stderr F {"component":"virt-handler","level":"error","msg":"failed to scrape metrics from //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock","pos":"scrapper.go:48","reason":"failed to update domain stats from socket //pods/f8bdfaf2-ddf3-455d-9137-8ca4d718066d/volumes/kubernetes.io~empty-dir/sockets/launcher-sock: unknown error encountered sending command GetDomainStats: rpc error: code = DeadlineExceeded desc = context deadline exceeded","timestamp":"2025-11-28T01:21:44.026665Z"}
2025-11-28T09:22:14.859781152+08:00 stderr F {"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:350","timestamp":"2025-11-28T01:22:14.859684Z"}
2025-11-28T09:22:14.859793066+08:00 stderr F {"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:351","timestamp":"2025-11-28T01:22:14.859710Z"}
2025-11-28T09:22:14.859794394+08:00 stderr F {"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:352","timestamp":"2025-11-28T01:22:14.859719Z"}
2025-11-28T09:22:58.335157643+08:00 stderr F {"component":"virt-handler","level":"info","msg":"resyncing virt-launcher domains","pos":"domain-watcher.go:137","timestamp":"2025-11-28T01:22:58.334774Z"}
2025-11-28T09:22:58.344709361+08:00 stderr F {"component":"virt-handler","kind":"","level":"info","msg":"VMI is in phase: Running | Domain status: Running, reason: Unknown","name":"kubevirt-1l600-test","namespace":"cideploy","pos":"vm.go:1899","timestamp":"2025-11-28T01:22:58.344477Z","uid":"a4368497-7943-444c-927b-176415bc8861"}
2025-11-28T09:22:58.345529092+08:00 stderr F {"component":"virt-handler","level":"info","msg":"initialized a new cgroup v1 manager successfully. controllerPaths: map[:/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope blkio:/blkio/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpu:/cpu/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpuacct:/cpuacct/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope cpuset:/cpuset/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope devices:/devices/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope freezer:/freezer/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope hugetlb:/hugetlb/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope memory:/memory/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope name=systemd:/name=systemd/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope net_cls:/net_cls/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope net_prio:/net_prio/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope perf_event:/perf_event/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope pids:/pids/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope rdma:/rdma/kubepods.slice/kubepods-podf8bdfaf2_ddf3_455d_9137_8ca4d718066d.slice/cri-containerd-a65252916ba6f418efebb9ff28d76f3b73a6a920ff6c72431a34fbfc1f6fbcf5.scope], procCgroupBasePath: /proc/774138/cgroup","pos":"cgroup.go:135","timestamp":"2025-11-28T01:22:58.345267Z"}
2025-11-28T09:23:44.857601992+08:00 stderr F {"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:350","timestamp":"2025-11-28T01:23:44.857303Z"}
2025-11-28T09:23:44.857650682+08:00 stderr F {"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:351","timestamp":"2025-11-28T01:23:44.857392Z"}
2025-11-28T09:23:44.857658643+08:00 stderr F {"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:352","timestamp":"2025-11-28T01:23:44.857430Z"}

Could anyone help me figure out where the problem lies?

[Or Mergi]

Is there a chance most of the time went on pulling the OS image?

Could you share the VM/VMI/pod events?

--
You received this message because you are subscribed to the Google Groups "kubevirt-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to kubevirt-dev...@googlegroups.com.
To view this discussion visit https://groups.google.com/d/msgid/kubevirt-dev/35e151fb-4804-4e0f-a83f-49bc77776d5bn%40googlegroups.com.

--

Or Mergi