kubevirt icon indicating copy to clipboard operation
kubevirt copied to clipboard

"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: No such file or directory"

Open mansoncui opened this issue 1 year ago • 35 comments

error info:

{"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon failed: virError(Code=38, Domain=7, Message='Failed toconnect socket to '/var/run/libvirt/virtqemud-sock': No such file or directory')","pos":"libvirt.go:553","timestamp":"2023-10-22T07:05:51.347975Z"}

{"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: No such file or directory","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"46","timestamp":"2023-10-22T07:05:51.373000Z"} {"component":"virt-launcher","level":"error","msg":"internal error: Unable to get session bus connection: Cannot spawn a message bus without a machine-id: Unable to load /var/lib/dbus/machine-id or /etc/machine-id: Failed to open file “/var/lib/dbus/machine-id”: No such file or directory","pos":"virGDBusGetSessionBus:126","subcomponent":"libvirt","thread":"46","timestamp":"2023-10-22T07:05:51.373000Z"} {"component":"virt-launcher","level":"error","msg":"internal error: Unable to get system bus connection: Could not connect: No such file or directory","pos":"virGDBusGetSystemBus:99","subcomponent":"libvirt","thread":"46","timestamp":"2023-10-22T07:05:51.374000Z"} {"component":"virt-launcher","level":"info","msg":"Connected to libvirt daemon","pos":"libvirt.go:561","timestamp":"2023-10-22T07:05:51.851830Z"}

image

Environment:

  • KubeVirt version (use virtctl version): v1.1.0-alpha.0
  • Kubernetes version (use kubectl version): 1.23.6
  • VM or VMI specifications:
  • Cloud provider or hardware configuration: 云物理机
  • OS (e.g. from /etc/os-release): Ubuntu 18.04.3 LTS
  • Kernel (e.g. uname -a): 5.4.193-0504193-generic

mansoncui avatar Oct 22 '23 07:10 mansoncui

Does your host supprot kvm? You can check by installing and running virt-host-validate. Another possibility is to enable software emulation.

alicefr avatar Oct 24 '23 14:10 alicefr

image 硬件虚拟化已经开启了

mansoncui avatar Oct 25 '23 02:10 mansoncui

image

mansoncui avatar Oct 25 '23 03:10 mansoncui

This looks similar to https://github.com/kubevirt/kubevirt/issues/10555. @mansoncui, I see that you use v1.1.0-alpha.0. Could you try with v1.0.0? Also, could you please share more info about your environment? What Kubernetes distro and container runtime are you using? K8s 1.23.6 is a bit too old for running the latest KubeVirt... though it may work to some extent.

vasiliy-ul avatar Oct 25 '23 05:10 vasiliy-ul

image

v1.0.0 same error reported

mansoncui avatar Oct 25 '23 12:10 mansoncui

Is it Minikube / Kind or some other Kubernetes distro?

vasiliy-ul avatar Oct 25 '23 12:10 vasiliy-ul

kubernetes binary install

mansoncui avatar Oct 27 '23 08:10 mansoncui

Please attach full virt-handler and virt-launcher logs.

vasiliy-ul avatar Oct 27 '23 09:10 vasiliy-ul

Please attach full virt-handler and virt-launcher logs.

{"component":"virt-launcher","level":"info","msg":"Collected all requested hook sidecar sockets","pos":"manager.go:86","timestamp":"2023-10-31T00:16:17.997500Z"} {"component":"virt-launcher","level":"info","msg":"Sorted all collected sidecar sockets per hook point based on their priority and name: map[]","pos":"manager.go:89","timestamp":"2023-10-31T00:16:17.997573Z"} {"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon: qemu+unix:///session?socket=/var/run/libvirt/virtqemud-sock","pos":"libvirt.go:524","timestamp":"2023-10-31T00:16:17.998737Z"} {"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon failed: virError(Code=38, Domain=7, Message='Failed to connect socket to '/var/run/libvirt/virtqemud-sock': No such file or directory')","pos":"libvirt.go:532","timestamp":"2023-10-31T00:16:17.999220Z"} {"component":"virt-launcher","level":"info","msg":"libvirt version: 9.0.0, package: 3.el9 ([email protected], 2023-02-01-12:58:56, )","subcomponent":"libvirt","thread":"42","timestamp":"2023-10-31T00:16:18.025000Z"} {"component":"virt-launcher","level":"info","msg":"hostname: testvm","subcomponent":"libvirt","thread":"42","timestamp":"2023-10-31T00:16:18.025000Z"} {"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: Permission denied","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"42","timestamp":"2023-10-31T00:16:18.025000Z"} {"component":"virt-launcher","level":"error","msg":"internal error: Unable to get session bus connection: Cannot spawn a message bus without a machine-id: Unable to load /var/lib/dbus/machine-id or /etc/machine-id: Failed to open file “/var/lib/dbus/machine-id”: No such file or directory","pos":"virGDBusGetSessionBus:126","subcomponent":"libvirt","thread":"42","timestamp":"2023-10-31T00:16:18.025000Z"} {"component":"virt-launcher","level":"error","msg":"internal error: Unable to get system bus connection: Could not connect: No such file or directory","pos":"virGDBusGetSystemBus:99","subcomponent":"libvirt","thread":"42","timestamp":"2023-10-31T00:16:18.025000Z"} {"component":"virt-launcher","level":"info","msg":"Connected to libvirt daemon","pos":"libvirt.go:540","timestamp":"2023-10-31T00:16:18.502105Z"} {"component":"virt-launcher","level":"info","msg":"Registered libvirt event notify callback","pos":"client.go:539","timestamp":"2023-10-31T00:16:18.506775Z"} {"component":"virt-launcher","level":"info","msg":"Marked as ready","pos":"virt-launcher.go:75","timestamp":"2023-10-31T00:16:18.507120Z"} {"component":"virt-launcher","level":"info","msg":"Received signal terminated","pos":"virt-launcher.go:457","timestamp":"2023-10-31T00:16:22.903185Z"} {"component":"virt-launcher","level":"info","msg":"stopping cmd server","pos":"server.go:611","timestamp":"2023-10-31T00:16:22.903334Z"} {"component":"virt-launcher","level":"info","msg":"cmd server stopped","pos":"server.go:620","timestamp":"2023-10-31T00:16:22.903652Z"} {"component":"virt-launcher","level":"info","msg":"Exiting...","pos":"virt-launcher.go:493","timestamp":"2023-10-31T00:16:22.903718Z"} {"component":"virt-launcher-monitor","level":"info","msg":"Reaped pid 26 with status 9","pos":"virt-launcher-monitor.go:125","timestamp":"2023-10-31T00:16:22.905146Z"} {"component":"virt-launcher-monitor","level":"info","msg":"Reaped pid 25 with status 9","pos":"virt-launcher-monitor.go:125","timestamp":"2023-10-31T00:16:22.905499Z"} {"component":"virt-launcher-monitor","level":"info","msg":"Reaped pid 12 with status 0","pos":"virt-launcher-monitor.go:125","timestamp":"2023-10-31T00:16:22.908362Z"}

mansoncui avatar Oct 31 '23 00:10 mansoncui

Previously, the error in the log was Unable to open /dev/kvm: No such file or directory:

{"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: No such file or directory","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"46","timestamp":"2023-10-22T07:05:51.373000Z"}

Now it is Unable to open /dev/kvm: Permission denied:

{"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: Permission denied","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"42","timestamp":"2023-10-31T00:16:18.025000Z"}

What is the difference between the two runs?

The host OS is Ubuntu, right? Do you have apparmor enabled? Also, please, attach the logs of the virt-handler pod. If you have several nodes, the log should come from the node where VMs fail to start.

vasiliy-ul avatar Oct 31 '23 07:10 vasiliy-ul

Any update on, I see v1.1.0 is the now the stable release. I am still facing the issue. My cluster is k8s "v1.27.2" kubevirt v1.0.0 and lower works. Both upgrade and fresh install to v1.1.0-alpha or v1.1.0 fails with the above error. https://github.com/kubevirt/kubevirt/issues/10555 Can someone please look and suggest.

vsundarraj-px avatar Nov 10 '23 05:11 vsundarraj-px

@vsundarraj-px, please provide some details about your environment and issue:

  • your host OS
  • do you have apparmor/selinux enabled?
  • bare-metal or nested?
  • check the comment https://github.com/kubevirt/kubevirt/issues/10605#issuecomment-1777346409
  • what is your k8s distro (minikube, kind, kubeadm, k3s, etc.)?
  • what is your container runtime (containerd, cri-o, docker, etc.)?
  • full virt-launcher log
  • full virt-handler log

vasiliy-ul avatar Nov 10 '23 06:11 vasiliy-ul

Host OS: CentOS Linux release 7.9.2009 (Core)Apparmor enabled Nested

k8s distro kubeadm container runtime: containerd getenforce Disabled

virt-launcher log kl virt-launcher-testvm-96wml Error from server (BadRequest): container "compute" in pod "virt-launcher-testvm-96wml" is waiting to start: PodInitializing [root@ip-10-13-157-255 ~]# kl virt-launcher-testvm-96wml -f {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-10T09:52:19.482202Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-10T09:52:19.583122Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-10T09:52:19.683590Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-10T09:52:19.783969Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-10T09:52:19.884870Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-10T09:52:19.985404Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-10T09:52:20.085850Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/96e84773-de48-46f5-91dd-65a30a973200/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-10T09:52:20.186458Z"} {"component":"virt-launcher","level":"info","msg":"Collected all requested hook sidecar sockets","pos":"manager.go:86","timestamp":"2023-11-10T09:52:20.249393Z"} {"component":"virt-launcher","level":"info","msg":"Sorted all collected sidecar sockets per hook point based on their priority and name: map[]","pos":"manager.go:89","timestamp":"2023-11-10T09:52:20.249547Z"} {"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon: qemu:///system","pos":"libvirt.go:563","timestamp":"2023-11-10T09:52:20.325034Z"} {"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon failed: virError(Code=38, Domain=7, Message='Failed to connect socket to '/var/run/libvirt/virtqemud-sock': No such file or directory')","pos":"libvirt.go:571","timestamp":"2023-11-10T09:52:20.370037Z"} {"component":"virt-launcher","level":"info","msg":"libvirt version: 9.5.0, package: 6.el9 ([email protected], 2023-08-25-08:53:56, )","subcomponent":"libvirt","thread":"42","timestamp":"2023-11-10T09:52:20.493000Z"} {"component":"virt-launcher","level":"info","msg":"hostname: testvm","subcomponent":"libvirt","thread":"42","timestamp":"2023-11-10T09:52:20.493000Z"} {"component":"virt-launcher","level":"error","msg":"internal error: Child process (dmidecode -q -t 0,1,2,3,4,11,17) unexpected exit status 1: /dev/mem: No such file or directory","pos":"virCommandWait:2750","subcomponent":"libvirt","thread":"42","timestamp":"2023-11-10T09:52:20.493000Z"} {"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: No such file or directory","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"42","timestamp":"2023-11-10T09:52:20.497000Z"} {"component":"virt-launcher","level":"info","msg":"Connected to libvirt daemon","pos":"libvirt.go:579","timestamp":"2023-11-10T09:52:20.879423Z"} {"component":"virt-launcher","level":"info","msg":"Registered libvirt event notify callback","pos":"client.go:562","timestamp":"2023-11-10T09:52:21.129611Z"} {"component":"virt-launcher","level":"info","msg":"Marked as ready","pos":"virt-launcher.go:75","timestamp":"2023-11-10T09:52:21.131006Z"}

virt-handler logs

`[root@ip-10-13-157-255 ~]# kubectl logs virt-handler-62rqg -n kubevirt Defaulted container "virt-handler" out of: virt-handler, virt-launcher (init) {"component":"virt-handler","level":"info","msg":"hostname ip-10-13-159-111.pwx.purestorage.com","pos":"virt-handler.go:208","timestamp":"2023-11-10T09:55:13.750277Z"} W1110 09:55:13.782258 27049 client_config.go:618] 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:509","timestamp":"2023-11-10T09:55:13.834471Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:13.834463Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:13.834516Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:13.834536Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:13.834555Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:13.834547Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:13.834589Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:13.834631Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:13.834590Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:13.834690Z"} {"component":"virt-handler","level":"error","msg":"something happened during opening kvm file: open /dev/kvm: no such file or directory","pos":"kvm-caps-info-plugin_amd64.go:227","timestamp":"2023-11-10T09:55:13.863400Z"} {"component":"virt-handler","level":"info","msg":"node-labeller is running","pos":"node_labeller.go:117","timestamp":"2023-11-10T09:55:13.863535Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:13.863667Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:13.863703Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:13.863736Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:13.863789Z"} {"component":"virt-handler","level":"info","msg":"Starting domain stats collector: node name=ip-10-13-159-111.pwx.purestorage.com","pos":"prometheus.go:586","timestamp":"2023-11-10T09:55:15.867117Z"} {"component":"virt-handler","level":"info","msg":"STARTING informer kubeVirtInformer","pos":"virtinformers.go:345","timestamp":"2023-11-10T09:55:15.867213Z"} {"component":"virt-handler","level":"info","msg":"STARTING informer extensionsKubeVirtCAConfigMapInformer","pos":"virtinformers.go:345","timestamp":"2023-11-10T09:55:15.867246Z"} {"component":"virt-handler","level":"info","msg":"STARTING informer vmiInformer-sources","pos":"virtinformers.go:345","timestamp":"2023-11-10T09:55:15.867263Z"} {"component":"virt-handler","level":"info","msg":"STARTING informer vmiInformer-targets","pos":"virtinformers.go:345","timestamp":"2023-11-10T09:55:15.867274Z"} {"component":"virt-handler","level":"info","msg":"STARTING informer CRDInformer","pos":"virtinformers.go:345","timestamp":"2023-11-10T09:55:15.867285Z"} {"component":"virt-handler","level":"info","msg":"metrics: max concurrent requests=3","pos":"virt-handler.go:565","timestamp":"2023-11-10T09:55:15.867587Z"} {"component":"virt-handler","level":"info","msg":"certificate with common name 'kubevirt.io:system:node:virt-handler' retrieved.","pos":"cert-manager.go:198","timestamp":"2023-11-10T09:55:15.868120Z"} {"component":"virt-handler","level":"info","msg":"certificate with common name 'kubevirt.io:system:client:virt-handler' retrieved.","pos":"cert-manager.go:198","timestamp":"2023-11-10T09:55:15.872694Z"} {"component":"virt-handler","level":"info","msg":"Updating cluster config from KubeVirt to resource version '5235929'","pos":"configuration.go:363","timestamp":"2023-11-10T09:55:15.882552Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:15.882820Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:15.882868Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:15.882888Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:15.882933Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:16.267782Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:16.267921Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:16.267860Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:16.267954Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:16.267979Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:16.267977Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:16.267890Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:16.267976Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:16.268459Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:16.268524Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:16.268527Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:16.268655Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:16.268682Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:16.268681Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:16.268732Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:16.268666Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:16.339171Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:16.339268Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:16.339286Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:16.339334Z"} {"component":"virt-handler","level":"info","msg":"Starting virt-handler controller.","pos":"vm.go:1529","timestamp":"2023-11-10T09:55:16.339511Z"} {"component":"virt-handler","level":"info","msg":"Starting a device plugin for device: kvm","pos":"device_controller.go:58","timestamp":"2023-11-10T09:55:16.339956Z"} {"component":"virt-handler","level":"info","msg":"Starting a device plugin for device: tun","pos":"device_controller.go:58","timestamp":"2023-11-10T09:55:16.340084Z"} {"component":"virt-handler","level":"info","msg":"Starting a device plugin for device: vhost-net","pos":"device_controller.go:58","timestamp":"2023-11-10T09:55:16.340107Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:16.340151Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:16.340306Z"} {"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:350","timestamp":"2023-11-10T09:55:16.340379Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:16.340328Z"} {"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:351","timestamp":"2023-11-10T09:55:16.340411Z"} {"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:352","timestamp":"2023-11-10T09:55:16.340439Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:16.340421Z"} {"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:350","timestamp":"2023-11-10T09:55:16.340467Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:16.340538Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:16.340559Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:16.340575Z"} {"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:351","timestamp":"2023-11-10T09:55:16.340556Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:16.340591Z"} {"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:352","timestamp":"2023-11-10T09:55:16.340601Z"} {"component":"virt-handler","level":"info","msg":"kvm device plugin started","pos":"generic_device.go:156","timestamp":"2023-11-10T09:55:16.350209Z"} {"component":"virt-handler","level":"warning","msg":"device '/dev/kvm' is not present, the device plugin can't expose it.","pos":"generic_device.go:297","timestamp":"2023-11-10T09:55:16.350337Z"} {"component":"virt-handler","level":"info","msg":"device '/dev/kvm' is present.","pos":"generic_device.go:300","timestamp":"2023-11-10T09:55:16.350610Z"} {"component":"virt-handler","level":"info","msg":"vhost-net device plugin started","pos":"generic_device.go:156","timestamp":"2023-11-10T09:55:16.354543Z"} {"component":"virt-handler","level":"info","msg":"device '/dev/vhost-net' is present.","pos":"generic_device.go:300","timestamp":"2023-11-10T09:55:16.354751Z"} {"component":"virt-handler","level":"info","msg":"tun device plugin started","pos":"generic_device.go:156","timestamp":"2023-11-10T09:55:16.355742Z"} {"component":"virt-handler","level":"info","msg":"device '/dev/net/tun' is present.","pos":"generic_device.go:300","timestamp":"2023-11-10T09:55:16.355859Z"} {"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:350","timestamp":"2023-11-10T09:55:16.404625Z"} {"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:351","timestamp":"2023-11-10T09:55:16.404673Z"} {"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:352","timestamp":"2023-11-10T09:55:16.404687Z"} {"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:350","timestamp":"2023-11-10T09:55:16.440513Z"} {"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:351","timestamp":"2023-11-10T09:55:16.440576Z"} {"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:352","timestamp":"2023-11-10T09:55:16.440596Z"} W1110 09:55:47.748960 27049 client_config.go:618] 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 '5237434'","pos":"configuration.go:363","timestamp":"2023-11-10T09:55:52.971668Z"} {"component":"virt-handler","level":"info","msg":"refreshed device plugins for permitted/forbidden host devices","pos":"device_controller.go:350","timestamp":"2023-11-10T09:55:52.971744Z"} {"component":"virt-handler","level":"info","msg":"enabled device-plugins for: []","pos":"device_controller.go:351","timestamp":"2023-11-10T09:55:52.972090Z"} {"component":"virt-handler","level":"info","msg":"disabled device-plugins for: []","pos":"device_controller.go:352","timestamp":"2023-11-10T09:55:52.972122Z"} {"component":"virt-handler","level":"info","msg":"Kubevirt Seccomp profile is not enabled","pos":"virt-handler.go:540","timestamp":"2023-11-10T09:55:52.972151Z"} {"component":"virt-handler","level":"info","msg":"set verbosity to 2","pos":"virt-handler.go:509","timestamp":"2023-11-10T09:55:52.972283Z"} {"component":"virt-handler","level":"info","msg":"setting rate limiter to 5 QPS and 10 Burst","pos":"virt-handler.go:518","timestamp":"2023-11-10T09:55:52.972427Z"} {"component":"virt-handler","level":"info","msg":"VSOCK server is already stopped","pos":"server.go:32","timestamp":"2023-11-10T09:55:52.972825Z"}

virt-host-validate setlocale: No such file or directory QEMU: Checking for hardware virtualization : FAIL (Only emulated CPUs are available, performance will be significantly limited) QEMU: Checking if device /dev/vhost-net exists : PASS QEMU: Checking if device /dev/net/tun exists : PASS QEMU: Checking for cgroup 'memory' controller support : PASS QEMU: Checking for cgroup 'memory' controller mount-point : PASS QEMU: Checking for cgroup 'cpu' controller support : PASS QEMU: Checking for cgroup 'cpu' controller mount-point : PASS QEMU: Checking for cgroup 'cpuacct' controller support : PASS QEMU: Checking for cgroup 'cpuacct' controller mount-point : PASS QEMU: Checking for cgroup 'cpuset' controller support : PASS QEMU: Checking for cgroup 'cpuset' controller mount-point : PASS QEMU: Checking for cgroup 'devices' controller support : PASS QEMU: Checking for cgroup 'devices' controller mount-point : PASS QEMU: Checking for cgroup 'blkio' controller support : PASS QEMU: Checking for cgroup 'blkio' controller mount-point : PASS WARN (Unknown if this platform has IOMMU support) LXC: Checking for Linux >= 2.6.26 : PASS LXC: Checking for namespace ipc : PASS LXC: Checking for namespace mnt : PASS LXC: Checking for namespace pid : PASS LXC: Checking for namespace uts : PASS LXC: Checking for namespace net : PASS LXC: Checking for namespace user : PASS LXC: Checking for cgroup 'memory' controller support : PASS LXC: Checking for cgroup 'memory' controller mount-point : PASS LXC: Checking for cgroup 'cpu' controller support : PASS LXC: Checking for cgroup 'cpu' controller mount-point : PASS LXC: Checking for cgroup 'cpuacct' controller support : PASS LXC: Checking for cgroup 'cpuacct' controller mount-point : PASS LXC: Checking for cgroup 'cpuset' controller support : PASS LXC: Checking for cgroup 'cpuset' controller mount-point : PASS LXC: Checking for cgroup 'devices' controller support : PASS LXC: Checking for cgroup 'devices' controller mount-point : PASS LXC: Checking for cgroup 'blkio' controller support : PASS LXC: Checking for cgroup 'blkio' controller mount-point : PASS LXC: Checking if device /sys/fs/fuse/connections exists : PASS

On Ubuntu20 same issue, with apparmor enabled and disabled.

vsundarraj-px avatar Nov 10 '23 10:11 vsundarraj-px

Host OS: CentOS Linux release 7.9.2009 (Core)Apparmor enabled Nested

virt-host-validate setlocale: No such file or directory QEMU: Checking for hardware virtualization : FAIL (Only emulated CPUs are available, performance will be significantly limited)

@vsundarraj-px, your host does not seem to support nested virtualization. Have you tried this https://github.com/kubevirt/kubevirt/blob/main/docs/software-emulation.md?

vasiliy-ul avatar Nov 10 '23 10:11 vasiliy-ul

Host OS: CentOS Linux release 7.9.2009 (Core)Apparmor enabled

Nested

virt-host-validate

setlocale: No such file or directory

QEMU: Checking for hardware virtualization : FAIL (Only emulated CPUs are available, performance will be significantly limited)

@vsundarraj-px, your host does not seem to support nested virtualization. Have you tried this https://github.com/kubevirt/kubevirt/blob/main/docs/software-emulation.md?

Yes software emulation is enabled. Please note, i dont see the issue with v1.0.0. Im constantly facing this v1.1.0-alpha and stable. Its the same setup, same os, same feature gates. Works fine with v1.0.0 but fails with above error with v1.1.0x

vsundarraj-px avatar Nov 10 '23 14:11 vsundarraj-px

@vsundarraj-px, could you add the bellow metadata to your VM and collect virt-launcher logs?

metadata:
  labels:
    debugLogs: "true"
    logVerbosity: "6"
  annotations:
    kubevirt.io/keep-launcher-alive-after-failure: "true"

That should increase the verbosity. Perhaps we will see smth. Personally, for me, the emulation mode works fine.

Also, please share the output of k describe virt-launcher.

vasiliy-ul avatar Nov 13 '23 12:11 vasiliy-ul

Virt-launcher logs with network Interface defined. virt-launcher-logs.log

Virt-launcher logs without network interface defined. virt-launcher-logs-wo-nw.log

`k describe vm testvm Name: testvm Namespace: default Labels: Annotations: kubevirt.io/latest-observed-api-version: v1 kubevirt.io/storage-observed-api-version: v1 API Version: kubevirt.io/v1 Kind: VirtualMachine Metadata: Creation Timestamp: 2023-11-15T06:19:10Z Finalizers: kubevirt.io/virtualMachineControllerFinalize Generation: 1 Resource Version: 22299 UID: 8268d9c5-ebe7-47b4-bc69-61e189a8e3d5 Spec: Running: true Template: Metadata: Annotations: kubevirt.io/keep-launcher-alive-after-failure: true Creation Timestamp: Labels: Debug Logs: true kubevirt.io/domain: testvm kubevirt.io/size: small Log Verbosity: 6 Spec: Architecture: amd64 Domain: Devices: Disks: Disk: Bus: virtio Name: containerdisk Disk: Bus: virtio Name: cloudinitdisk Machine: Type: q35 Resources: Requests: Memory: 64M Volumes: Container Disk: Image: quay.io/kubevirt/cirros-container-disk-demo Name: containerdisk Cloud Init No Cloud: userDataBase64: SGkuXG4= Name: cloudinitdisk Status: Conditions: Last Probe Time: 2023-11-15T06:26:08Z Last Transition Time: 2023-11-15T06:26:08Z Message: Guest VM is not reported as running Reason: GuestNotRunning Status: False Type: Ready Last Probe Time: Last Transition Time: Message: cannot migrate VMI which does not use masquerade to connect to the pod network or bridge with kubevirt.io/allow-pod-bridge-network-live-migration VM annotation Reason: InterfaceNotLiveMigratable Status: False Type: LiveMigratable Last Probe Time: Last Transition Time: 2023-11-15T06:26:16Z Message: failed to configure vmi network: setup failed, err: open /proc/sys/net/ipv6/conf/all/forwarding: no such file or directory Reason: Synchronizing with the Domain failed. Status: False Type: Synchronized Created: true Desired Generation: 1 Observed Generation: 1 Printable Status: Starting Start Failure: Consecutive Fail Count: 1 Last Failed VMIUID: 9b4d2736-f23f-42fc-a2f1-1bd8b2d5144d Retry After Timestamp: 2023-11-15T06:25:22Z Volume Snapshot Statuses: Enabled: false Name: containerdisk Reason: Snapshot is not supported for this volumeSource type [containerdisk] Enabled: false Name: cloudinitdisk Reason: Snapshot is not supported for this volumeSource type [cloudinitdisk] Events: Type Reason Age From Message


Normal SuccessfulDelete 4m43s virtualmachine-controller Stopped the virtual machine by deleting the virtual machine instance 9b4d2736-f23f-42fc-a2f1-1bd8b2d5144d Normal SuccessfulCreate 3m42s (x2 over 10m) virtualmachine-controller Started the virtual machine by creating the new virtual machine instance testvm`

vsundarraj-px avatar Nov 15 '23 06:11 vsundarraj-px

@vasiliy-ul any update on this? There seems something trivial I'm missing. This is constantly reproducible on all of our nodes. surprised that its not reported much else where in the field.

vsundarraj-px avatar Nov 21 '23 04:11 vsundarraj-px

@vsundarraj-px, I personally cannot reproduce the issue on my setup.

Regarding the message:

Message: failed to configure vmi network: setup failed, err: open /proc/sys/net/ipv6/conf/all/forwarding: no such file or directory

This looks like you do not have ipv6 support on your machine. Is that right? I am not 100% sure if this is a critical error. I will probably tag network folks. Ping @EdDev, @maiqueb, hey guys, maybe you could suggest here?

vasiliy-ul avatar Nov 21 '23 07:11 vasiliy-ul

I am spinning up the VM without any network interface and I still face the issue. {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-21T10:26:03.713074Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-21T10:26:03.813627Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-21T10:26:03.914052Z"} {"component":"virt-launcher","level":"info","msg":"Collected all requested hook sidecar sockets","pos":"manager.go:86","timestamp":"2023-11-21T10:26:03.967781Z"} {"component":"virt-launcher","level":"info","msg":"Sorted all collected sidecar sockets per hook point based on their priority and name: map[]","pos":"manager.go:89","timestamp":"2023-11-21T10:26:03.967955Z"} {"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon: qemu:///system","pos":"libvirt.go:563","timestamp":"2023-11-21T10:26:03.973928Z"} {"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon failed: virError(Code=38, Domain=7, Message='Failed to connect socket to '/var/run/libvirt/virtqemud-sock': No such file or directory')","pos":"libvirt.go:571","timestamp":"2023-11-21T10:26:03.979306Z"} {"component":"virt-launcher","level":"info","msg":"libvirt version: 9.5.0, package: 6.el9 ([email protected], 2023-08-25-08:53:56, )","subcomponent":"libvirt","thread":"40","timestamp":"2023-11-21T10:26:04.016000Z"} {"component":"virt-launcher","level":"info","msg":"hostname: testvm","subcomponent":"libvirt","thread":"40","timestamp":"2023-11-21T10:26:04.016000Z"} {"component":"virt-launcher","level":"error","msg":"internal error: Child process (dmidecode -q -t 0,1,2,3,4,11,17) unexpected exit status 1: /dev/mem: No such file or directory","pos":"virCommandWait:2750","subcomponent":"libvirt","thread":"40","timestamp":"2023-11-21T10:26:04.016000Z"} {"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: No such file or directory","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"40","timestamp":"2023-11-21T10:26:04.019000Z"} {"component":"virt-launcher","level":"info","msg":"Connected to libvirt daemon","pos":"libvirt.go:579","timestamp":"2023-11-21T10:26:04.482741Z"} {"component":"virt-launcher","level":"info","msg":"Registered libvirt event notify callback","pos":"client.go:562","timestamp":"2023-11-21T10:26:04.488541Z"} {"component":"virt-launcher","level":"info","msg":"Marked as ready","pos":"virt-launcher.go:75","timestamp":"2023-11-21T10:26:04.489147Z"} [root@ip-10-13-157-255 ~]# k get vm NAME AGE STATUS READY testvm 34s Starting False [root@ip-10-13-157-255 ~]# gl virt-launcher-testvm-s4c9r -f {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-21T10:26:03.713074Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-21T10:26:03.813627Z"} {"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/d89f0ace-7d06-431d-9422-7e54ed8c0f02/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-21T10:26:03.914052Z"} {"component":"virt-launcher","level":"info","msg":"Collected all requested hook sidecar sockets","pos":"manager.go:86","timestamp":"2023-11-21T10:26:03.967781Z"} {"component":"virt-launcher","level":"info","msg":"Sorted all collected sidecar sockets per hook point based on their priority and name: map[]","pos":"manager.go:89","timestamp":"2023-11-21T10:26:03.967955Z"} {"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon: qemu:///system","pos":"libvirt.go:563","timestamp":"2023-11-21T10:26:03.973928Z"} {"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon failed: virError(Code=38, Domain=7, Message='Failed to connect socket to '/var/run/libvirt/virtqemud-sock': No such file or directory')","pos":"libvirt.go:571","timestamp":"2023-11-21T10:26:03.979306Z"} {"component":"virt-launcher","level":"info","msg":"libvirt version: 9.5.0, package: 6.el9 ([email protected], 2023-08-25-08:53:56, )","subcomponent":"libvirt","thread":"40","timestamp":"2023-11-21T10:26:04.016000Z"} {"component":"virt-launcher","level":"info","msg":"hostname: testvm","subcomponent":"libvirt","thread":"40","timestamp":"2023-11-21T10:26:04.016000Z"} {"component":"virt-launcher","level":"error","msg":"internal error: Child process (dmidecode -q -t 0,1,2,3,4,11,17) unexpected exit status 1: /dev/mem: No such file or directory","pos":"virCommandWait:2750","subcomponent":"libvirt","thread":"40","timestamp":"2023-11-21T10:26:04.016000Z"} {"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: No such file or directory","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"40","timestamp":"2023-11-21T10:26:04.019000Z"} {"component":"virt-launcher","level":"info","msg":"Connected to libvirt daemon","pos":"libvirt.go:579","timestamp":"2023-11-21T10:26:04.482741Z"} {"component":"virt-launcher","level":"info","msg":"Registered libvirt event notify callback","pos":"client.go:562","timestamp":"2023-11-21T10:26:04.488541Z"} {"component":"virt-launcher","level":"info","msg":"Marked as ready","pos":"virt-launcher.go:75","timestamp":"2023-11-21T10:26:04.489147Z"}

I dont think this is related to ipv6 support on host or not.

Last Transition Time: 2023-11-21T10:26:06Z Message: failed to configure vmi network: setup failed, err: open /proc/sys/net/ipv4/ip_unprivileged_port_start: no such file or directory Reason: Synchronizing with the Domain failed.

The vm profile is this

`apiVersion: kubevirt.io/v1

kind: VirtualMachine metadata: name: testvm annotations: kubevirt.io/keep-launcher-alive-after-failure: "true" spec: running: true template: metadata: labels: kubevirt.io/size: small kubevirt.io/domain: testvm spec: domain: devices: disks: - name: containerdisk disk: bus: virtio - name: cloudinitdisk disk: bus: virtio resources: requests: memory: 64M volumes: - name: containerdisk containerDisk: image: quay.io/kubevirt/cirros-container-disk-demo - name: cloudinitdisk cloudInitNoCloud: userDataBase64: SGkuXG4=`

vsundarraj-px avatar Nov 21 '23 10:11 vsundarraj-px

I dont think this is related to ipv6 support on host or not.

Last Transition Time: 2023-11-21T10:26:06Z Message: failed to configure vmi network: setup failed, err: open /proc/sys/net/ipv4/ip_unprivileged_port_start: no such file or directory Reason: Synchronizing with the Domain failed.

This one is not ipv6, but still it's about networking. Hm... so you really have no /proc/sys/net/ipv4/ip_unprivileged_port_start on your host?

vasiliy-ul avatar Nov 21 '23 10:11 vasiliy-ul

Is there a kernel version pre-req for v1.1.0 release? /proc/sys/net/ipv4/ip_unprivileged_port_start available only from kernel version 4.11 on wards. My nodes are 3.10.x

vsundarraj-px avatar Nov 22 '23 10:11 vsundarraj-px

And isnt this missleading error? as my vm is configured without any network interface.

vsundarraj-px avatar Nov 22 '23 10:11 vsundarraj-px

Is there a kernel version pre-req for v1.1.0 release?

AFAIK, there are no documented kernel requirements. However, KubeVirt relies on certain functionality being present and assumes a more or less recent version.

vasiliy-ul avatar Nov 22 '23 12:11 vasiliy-ul

Any update on, I see v1.1.0 is the now the stable release. I am still facing the issue. My cluster is k8s "v1.27.2" kubevirt v1.0.0 and lower works. Both upgrade and fresh install to v1.1.0-alpha or v1.1.0 fails with the above error. #10555 Can someone please look and suggest.

➕ 1️⃣ @vsundarraj-px I have reproduced this behavior as well on kubevirt v1.1.0. I will revert to kubevirt v1.0.0 and update this post with my findings soon...


Environment:

  • KubeVirt version: v1.1.0
  • Kubernetes version: v1.28.2+k3s1 (k3s)
  • VM or VMI specifications: using testvm from kubevirt docs (https://kubevirt.io/labs/manifests/vm.yaml)
  • Hardware configuration: Bare Metal, Intel i7-10700TE CPU @ 2.00GHz (cores=8 enabledcores=8 microcode=248 threads=16)
  • OS/Kernel: Ubuntu 22.04 / 5.15.0-89-generic and ALSO reproduced on Ubuntu 23.10 / 6.5.0-13-generic
  • Install tools: ansible --> k3sup --> kube-virt operator
kind: KubeVirt
metadata:
  name: kubevirt
  namespace: kubevirt
 spec:
   certificateRotateStrategy: {}
   configuration:
     developerConfiguration:
       featureGates: []
   customizeComponents: {}
   imagePullPolicy: IfNotPresent
   workloadUpdateStrategy: {}

What happened: VM creation fails.

What you expected to happen: Successful VM creation.

How to reproduce it (as minimally and precisely as possible): Using kubevirt testvm manifest (src: https://kubevirt.io/labs/manifests/vm.yaml )

Additional context:

virt-launcher-monitor logs

#:~$ kubectl logs virt-launcher-testvm-7csnf -f
{"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/e2cdb8b8-721a-407e-8bbd-22c8813cc5bb/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/e2cdb8b8-721a-407e-8bbd-22c8813cc5bb/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-29T16:59:20.879898Z"}
{"component":"virt-launcher","level":"info","msg":"Collected all requested hook sidecar sockets","pos":"manager.go:86","timestamp":"2023-11-29T16:59:20.924886Z"}
{"component":"virt-launcher","level":"info","msg":"Sorted all collected sidecar sockets per hook point based on their priority and name: map[]","pos":"manager.go:89","timestamp":"2023-11-29T16:59:20.924934Z"}
{"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon: qemu+unix:///session?socket=/var/run/libvirt/virtqemud-sock","pos":"libvirt.go:563","timestamp":"2023-11-29T16:59:20.925117Z"}
{"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon failed: virError(Code=38, Domain=7, Message='Failed to connect socket to '/var/run/libvirt/virtqemud-sock': No such file or directory')","pos":"libvirt.go:571","timestamp":"2023-11-29T16:59:20.925400Z"}
{"component":"virt-launcher","level":"info","msg":"libvirt version: 9.5.0, package: 6.el9 ([email protected], 2023-08-25-08:53:56, )","subcomponent":"libvirt","thread":"45","timestamp":"2023-11-29T16:59:20.934000Z"}
{"component":"virt-launcher","level":"info","msg":"hostname: testvm","subcomponent":"libvirt","thread":"45","timestamp":"2023-11-29T16:59:20.934000Z"}
{"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: Permission denied","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"45","timestamp":"2023-11-29T16:59:20.934000Z"}
{"component":"virt-launcher","level":"error","msg":"internal error: Unable to get session bus connection: Cannot spawn a message bus without a machine-id: Unable to load /var/lib/dbus/machine-id or /etc/machine-id: Failed to open file “/var/lib/dbus/machine-id”: No such file or directory","pos":"virGDBusGetSessionBus:126","subcomponent":"libvirt","thread":"45","timestamp":"2023-11-29T16:59:20.935000Z"}
{"component":"virt-launcher","level":"error","msg":"internal error: Unable to get system bus connection: Could not connect: No such file or directory","pos":"virGDBusGetSystemBus:99","subcomponent":"libvirt","thread":"45","timestamp":"2023-11-29T16:59:20.935000Z"}
{"component":"virt-launcher","level":"info","msg":"Connected to libvirt daemon","pos":"libvirt.go:579","timestamp":"2023-11-29T16:59:21.428772Z"}
{"component":"virt-launcher","level":"info","msg":"Registered libvirt event notify callback","pos":"client.go:562","timestamp":"2023-11-29T16:59:21.433998Z"}
{"component":"virt-launcher","level":"info","msg":"Marked as ready","pos":"virt-launcher.go:75","timestamp":"2023-11-29T16:59:21.434361Z"}

panic: timed out waiting for domain to be defined

goroutine 1 [running]:
main.waitForDomainUUID(0xc000709140?, 0xc000709020, 0xc00010f6e0, {0x1f06608, 0xc0001ee410})
	cmd/virt-launcher/virt-launcher.go:255 +0x625
main.main()
	cmd/virt-launcher/virt-launcher.go:483 +0x1205
{"component":"virt-launcher-monitor","level":"info","msg":"Reaped pid 12 with status 512","pos":"virt-launcher-monitor.go:192","timestamp":"2023-11-29T17:03:25.447323Z"}
{"component":"virt-launcher-monitor","level":"error","msg":"dirty virt-launcher shutdown: exit-code 2","pos":"virt-launcher-monitor.go:210","timestamp":"2023-11-29T17:03:25.447580Z"}
{"component":"virt-launcher-monitor","level":"error","msg":"failed to open file /var/run/kubevirt/passt.log","pos":"virt-launcher-monitor.go:421","reason":"open /var/run/kubevirt/passt.log: no such file or directory","timestamp":"2023-11-29T17:03:25.447685Z"}

virt-host-validate

  QEMU: Checking for hardware virtualization                                 : PASS
  QEMU: Checking if device /dev/kvm exists                                   : PASS
  QEMU: Checking if device /dev/kvm is accessible                            : PASS
  QEMU: Checking if device /dev/vhost-net exists                             : PASS
  QEMU: Checking if device /dev/net/tun exists                               : PASS
  QEMU: Checking for cgroup 'cpu' controller support                         : PASS
  QEMU: Checking for cgroup 'cpuacct' controller support                     : PASS
  QEMU: Checking for cgroup 'cpuset' controller support                      : PASS
  QEMU: Checking for cgroup 'memory' controller support                      : PASS
  QEMU: Checking for cgroup 'devices' controller support                     : PASS
  QEMU: Checking for cgroup 'blkio' controller support                       : PASS
  QEMU: Checking for device assignment IOMMU support                         : PASS

Update 2023-11-29 20:15 UTC:

After uninstalling kubevirt v1.1.0 and installing v1.0.1, I have confirmed the issue above is no longer present.
The testvm starts up and reaches a healthy state. This confirms kubevirt v1.0.1 works as expected.

#:~$ kubectl get vmi testvm -o wide
NAME     AGE     PHASE     IP             NODENAME     READY   LIVE-MIGRATABLE   PAUSED
testvm   3m31s   Running   172.29.0.154   lab2-edge1   True    True

virt-launcher-monitor logs

kc logs virt-launcher-testvm-jfvpb -f
{"component":"virt-launcher","level":"info","msg":"Collected all requested hook sidecar sockets","pos":"manager.go:86","timestamp":"2023-11-29T20:22:50.512918Z"}
{"component":"virt-launcher","level":"info","msg":"Sorted all collected sidecar sockets per hook point based on their priority and name: map[]","pos":"manager.go:89","timestamp":"2023-11-29T20:22:50.512964Z"}
{"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon: qemu+unix:///session?socket=/var/run/libvirt/virtqemud-sock","pos":"libvirt.go:524","timestamp":"2023-11-29T20:22:50.513503Z"}
{"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon failed: virError(Code=38, Domain=7, Message='Failed to connect socket to '/var/run/libvirt/virtqemud-sock': No such file or directory')","pos":"libvirt.go:532","timestamp":"2023-11-29T20:22:50.513805Z"}
{"component":"virt-launcher","level":"info","msg":"libvirt version: 9.0.0, package: 3.el9 ([email protected], 2023-02-01-12:58:56, )","subcomponent":"libvirt","thread":"48","timestamp":"2023-11-29T20:22:50.523000Z"}
{"component":"virt-launcher","level":"info","msg":"hostname: testvm","subcomponent":"libvirt","thread":"48","timestamp":"2023-11-29T20:22:50.523000Z"}
{"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: Permission denied","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"48","timestamp":"2023-11-29T20:22:50.523000Z"}
{"component":"virt-launcher","level":"error","msg":"internal error: Unable to get session bus connection: Cannot spawn a message bus without a machine-id: Unable to load /var/lib/dbus/machine-id or /etc/machine-id: Failed to open file “/var/lib/dbus/machine-id”: No such file or directory","pos":"virGDBusGetSessionBus:126","subcomponent":"libvirt","thread":"48","timestamp":"2023-11-29T20:22:50.524000Z"}
{"component":"virt-launcher","level":"error","msg":"internal error: Unable to get system bus connection: Could not connect: No such file or directory","pos":"virGDBusGetSystemBus:99","subcomponent":"libvirt","thread":"48","timestamp":"2023-11-29T20:22:50.524000Z"}
{"component":"virt-launcher","level":"info","msg":"Connected to libvirt daemon","pos":"libvirt.go:540","timestamp":"2023-11-29T20:22:51.017092Z"}
{"component":"virt-launcher","level":"info","msg":"Registered libvirt event notify callback","pos":"client.go:539","timestamp":"2023-11-29T20:22:51.022126Z"}
{"component":"virt-launcher","level":"info","msg":"Marked as ready","pos":"virt-launcher.go:75","timestamp":"2023-11-29T20:22:51.022531Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Executing PreStartHook on VMI pod environment","name":"testvm","namespace":"default","pos":"manager.go:623","timestamp":"2023-11-29T20:22:52.452199Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Starting PreCloudInitIso hook","name":"testvm","namespace":"default","pos":"manager.go:644","timestamp":"2023-11-29T20:22:52.452250Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","level":"info","msg":"Found nameservers in /etc/resolv.conf: \ufffd\u001d\u0008\n","pos":"network.go:293","timestamp":"2023-11-29T20:22:52.452814Z"}
{"component":"virt-launcher","level":"info","msg":"Found search domains in /etc/resolv.conf: default.svc.cluster.local svc.cluster.local cluster.local","pos":"network.go:294","timestamp":"2023-11-29T20:22:52.452838Z"}
{"component":"virt-launcher","level":"info","msg":"Starting SingleClientDHCPServer","pos":"server.go:65","timestamp":"2023-11-29T20:22:52.452889Z"}
{"component":"virt-launcher","level":"info","msg":"Driver cache mode for /var/run/kubevirt-ephemeral-disks/disk-data/containerdisk/disk.qcow2 set to none","pos":"converter.go:472","timestamp":"2023-11-29T20:22:52.460633Z"}
{"component":"virt-launcher","level":"info","msg":"Driver cache mode for /var/run/kubevirt-ephemeral-disks/cloud-init-data/default/testvm/noCloud.iso set to none","pos":"converter.go:472","timestamp":"2023-11-29T20:22:52.463449Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Domain XML generated. Base64 dump
....
.... <snip>
....
{"component":"virt-launcher","level":"info","msg":"Successfully connected to domain notify socket at /var/run/kubevirt/domain-notify-pipe.sock","pos":"client.go:170","timestamp":"2023-11-29T20:22:53.119577Z"}
{"component":"virt-launcher","level":"info","msg":"Domain name event: default_testvm","pos":"client.go:423","timestamp":"2023-11-29T20:22:53.123481Z"}
{"component":"virt-launcher","level":"info","msg":"Monitoring loop: rate 1s start timeout 4m31s","pos":"monitor.go:187","timestamp":"2023-11-29T20:22:53.125361Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Domain defined.","name":"testvm","namespace":"default","pos":"manager.go:1002","timestamp":"2023-11-29T20:22:53.144049Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","level":"info","msg":"DomainLifecycle event Domain event=\"defined\" detail=\"updated\" with event id 0 reason 1 received","pos":"client.go:465","timestamp":"2023-11-29T20:22:53.144056Z"}
{"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Shutoff(5):Unknown(0)","pos":"client.go:296","timestamp":"2023-11-29T20:22:53.149434Z"}
{"component":"virt-launcher","level":"info","msg":"Domain name event: default_testvm","pos":"client.go:423","timestamp":"2023-11-29T20:22:53.151159Z"}
{"component":"virt-launcher","level":"info","msg":"generated nocloud iso file /var/run/kubevirt-ephemeral-disks/cloud-init-data/default/testvm/noCloud.iso","pos":"cloud-init.go:674","timestamp":"2023-11-29T20:22:53.258158Z"}
{"component":"virt-launcher","level":"info","msg":"GuestAgentLifecycle event state 2 with reason 1 received","pos":"client.go:522","timestamp":"2023-11-29T20:22:53.314590Z"}
{"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Paused(3):StartingUp(11)","pos":"client.go:296","timestamp":"2023-11-29T20:22:53.315954Z"}
{"component":"virt-launcher","level":"info","msg":"Domain name event: default_testvm","pos":"client.go:423","timestamp":"2023-11-29T20:22:53.316688Z"}
{"component":"virt-launcher","level":"info","msg":"DomainLifecycle event Domain event=\"resumed\" detail=\"unpaused\" with event id 4 reason 0 received","pos":"client.go:465","timestamp":"2023-11-29T20:22:53.486742Z"}
{"component":"virt-launcher","level":"info","msg":"DomainLifecycle event Domain event=\"started\" detail=\"booted\" with event id 2 reason 0 received","pos":"client.go:465","timestamp":"2023-11-29T20:22:53.487854Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Domain started.","name":"testvm","namespace":"default","pos":"manager.go:1030","timestamp":"2023-11-29T20:22:53.488669Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Running(1):Unknown(1)","pos":"client.go:296","timestamp":"2023-11-29T20:22:53.489592Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Synced vmi","name":"testvm","namespace":"default","pos":"server.go:208","timestamp":"2023-11-29T20:22:53.489835Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","level":"info","msg":"Domain name event: default_testvm","pos":"client.go:423","timestamp":"2023-11-29T20:22:53.490357Z"}
{"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Running(1):Unknown(1)","pos":"client.go:296","timestamp":"2023-11-29T20:22:53.491293Z"}
{"component":"virt-launcher","level":"info","msg":"Domain name event: default_testvm","pos":"client.go:423","timestamp":"2023-11-29T20:22:53.492115Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Synced vmi","name":"testvm","namespace":"default","pos":"server.go:208","timestamp":"2023-11-29T20:22:53.534287Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Synced vmi","name":"testvm","namespace":"default","pos":"server.go:208","timestamp":"2023-11-29T20:22:53.555245Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Synced vmi","name":"testvm","namespace":"default","pos":"server.go:208","timestamp":"2023-11-29T20:22:53.605969Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","level":"info","msg":"Found PID for default_testvm: 86","pos":"monitor.go:148","timestamp":"2023-11-29T20:22:54.125751Z"}

scog avatar Nov 29 '23 17:11 scog

Sure, kubevirt-v1.0.1 works, v1.1.0 has fatal issues.

openqt avatar Nov 30 '23 11:11 openqt

I meet the same problem

CharlesQQ avatar Jan 04 '24 09:01 CharlesQQ

Me too. however ,CPU nested is working fine in VM

caijian76 avatar Jan 31 '24 03:01 caijian76

Single stack IPv4 is fixed in v1.2. It should also be available on a future v1.1.2 release if/when it will be available.

EdDev avatar Feb 16 '24 09:02 EdDev

任何更新,我看到 v1.1.0 是现在的稳定版本。我仍然面临这个问题。我的集群是 k8s “v1.27.2” kubevirt v1.0.0 及更低版本。升级和全新安装到 v1.1.0-alpha 或 v1.1.0 都失败,并出现上述错误。#10555有人可以看看并提出建议吗?

➕ 1️⃣ 我也在 kubevirt 上重现了这种行为。我将恢复到 kubevirt 并很快用我的发现更新这篇文章......v1.1.0``v1.0.0

环境

  • KubeVirt 版本:v1.1.0
  • Kubernetes 版本:(k3s)v1.28.2+k3s1
  • VM 或 VMI 规范:使用 from kubevirt docs (https://kubevirt.io/labs/manifests/vm.yamltestvm)
  • 硬件配置:裸机,Intel i7-10700TE CPU @ 2.00GHz(内核=8个启用的内核=8个微码=248个线程=16)
  • OS/Kernel: and ALSO reproduced on Ubuntu 22.04 / 5.15.0-89-generic``Ubuntu 23.10 / 6.5.0-13-generic
  • Install tools: ansible --> k3sup --> kube-virt operator
kind: KubeVirt
metadata:
  name: kubevirt
  namespace: kubevirt
 spec:
   certificateRotateStrategy: {}
   configuration:
     developerConfiguration:
       featureGates: []
   customizeComponents: {}
   imagePullPolicy: IfNotPresent
   workloadUpdateStrategy: {}

What happened: VM creation fails.

What you expected to happen: Successful VM creation.

How to reproduce it (as minimally and precisely as possible): Using kubevirt manifest (src: https://kubevirt.io/labs/manifests/vm.yamltestvm )

Additional context:

virt-launcher-monitor logs

#:~$ kubectl logs virt-launcher-testvm-7csnf -f
{"component":"virt-launcher-monitor","level":"error","msg":"could not create up serial console term file: /var/run/kubevirt-private/e2cdb8b8-721a-407e-8bbd-22c8813cc5bb/virt-serial0-log-sigTerm","pos":"virt-launcher-monitor.go:72","reason":"open /var/run/kubevirt-private/e2cdb8b8-721a-407e-8bbd-22c8813cc5bb/virt-serial0-log-sigTerm: no such file or directory","timestamp":"2023-11-29T16:59:20.879898Z"}
{"component":"virt-launcher","level":"info","msg":"Collected all requested hook sidecar sockets","pos":"manager.go:86","timestamp":"2023-11-29T16:59:20.924886Z"}
{"component":"virt-launcher","level":"info","msg":"Sorted all collected sidecar sockets per hook point based on their priority and name: map[]","pos":"manager.go:89","timestamp":"2023-11-29T16:59:20.924934Z"}
{"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon: qemu+unix:///session?socket=/var/run/libvirt/virtqemud-sock","pos":"libvirt.go:563","timestamp":"2023-11-29T16:59:20.925117Z"}
{"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon failed: virError(Code=38, Domain=7, Message='Failed to connect socket to '/var/run/libvirt/virtqemud-sock': No such file or directory')","pos":"libvirt.go:571","timestamp":"2023-11-29T16:59:20.925400Z"}
{"component":"virt-launcher","level":"info","msg":"libvirt version: 9.5.0, package: 6.el9 ([email protected], 2023-08-25-08:53:56, )","subcomponent":"libvirt","thread":"45","timestamp":"2023-11-29T16:59:20.934000Z"}
{"component":"virt-launcher","level":"info","msg":"hostname: testvm","subcomponent":"libvirt","thread":"45","timestamp":"2023-11-29T16:59:20.934000Z"}
{"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: Permission denied","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"45","timestamp":"2023-11-29T16:59:20.934000Z"}
{"component":"virt-launcher","level":"error","msg":"internal error: Unable to get session bus connection: Cannot spawn a message bus without a machine-id: Unable to load /var/lib/dbus/machine-id or /etc/machine-id: Failed to open file “/var/lib/dbus/machine-id”: No such file or directory","pos":"virGDBusGetSessionBus:126","subcomponent":"libvirt","thread":"45","timestamp":"2023-11-29T16:59:20.935000Z"}
{"component":"virt-launcher","level":"error","msg":"internal error: Unable to get system bus connection: Could not connect: No such file or directory","pos":"virGDBusGetSystemBus:99","subcomponent":"libvirt","thread":"45","timestamp":"2023-11-29T16:59:20.935000Z"}
{"component":"virt-launcher","level":"info","msg":"Connected to libvirt daemon","pos":"libvirt.go:579","timestamp":"2023-11-29T16:59:21.428772Z"}
{"component":"virt-launcher","level":"info","msg":"Registered libvirt event notify callback","pos":"client.go:562","timestamp":"2023-11-29T16:59:21.433998Z"}
{"component":"virt-launcher","level":"info","msg":"Marked as ready","pos":"virt-launcher.go:75","timestamp":"2023-11-29T16:59:21.434361Z"}

panic: timed out waiting for domain to be defined

goroutine 1 [running]:
main.waitForDomainUUID(0xc000709140?, 0xc000709020, 0xc00010f6e0, {0x1f06608, 0xc0001ee410})
	cmd/virt-launcher/virt-launcher.go:255 +0x625
main.main()
	cmd/virt-launcher/virt-launcher.go:483 +0x1205
{"component":"virt-launcher-monitor","level":"info","msg":"Reaped pid 12 with status 512","pos":"virt-launcher-monitor.go:192","timestamp":"2023-11-29T17:03:25.447323Z"}
{"component":"virt-launcher-monitor","level":"error","msg":"dirty virt-launcher shutdown: exit-code 2","pos":"virt-launcher-monitor.go:210","timestamp":"2023-11-29T17:03:25.447580Z"}
{"component":"virt-launcher-monitor","level":"error","msg":"failed to open file /var/run/kubevirt/passt.log","pos":"virt-launcher-monitor.go:421","reason":"open /var/run/kubevirt/passt.log: no such file or directory","timestamp":"2023-11-29T17:03:25.447685Z"}

virt-host-validate

  QEMU: Checking for hardware virtualization                                 : PASS
  QEMU: Checking if device /dev/kvm exists                                   : PASS
  QEMU: Checking if device /dev/kvm is accessible                            : PASS
  QEMU: Checking if device /dev/vhost-net exists                             : PASS
  QEMU: Checking if device /dev/net/tun exists                               : PASS
  QEMU: Checking for cgroup 'cpu' controller support                         : PASS
  QEMU: Checking for cgroup 'cpuacct' controller support                     : PASS
  QEMU: Checking for cgroup 'cpuset' controller support                      : PASS
  QEMU: Checking for cgroup 'memory' controller support                      : PASS
  QEMU: Checking for cgroup 'devices' controller support                     : PASS
  QEMU: Checking for cgroup 'blkio' controller support                       : PASS
  QEMU: Checking for device assignment IOMMU support                         : PASS

更新 2023-11-29 20:15 UTC:

卸载 kubevirt 并安装后,我已确认上述问题不再存在。启动并达到健康状态。这证实了 kubevirt 按预期工作。v1.1.0``v1.0.1``testvm``v1.0.1

#:~$ kubectl get vmi testvm -o wide
NAME     AGE     PHASE     IP             NODENAME     READY   LIVE-MIGRATABLE   PAUSED
testvm   3m31s   Running   172.29.0.154   lab2-edge1   True    True

virt-launcher-monitor logs

kc logs virt-launcher-testvm-jfvpb -f
{"component":"virt-launcher","level":"info","msg":"Collected all requested hook sidecar sockets","pos":"manager.go:86","timestamp":"2023-11-29T20:22:50.512918Z"}
{"component":"virt-launcher","level":"info","msg":"Sorted all collected sidecar sockets per hook point based on their priority and name: map[]","pos":"manager.go:89","timestamp":"2023-11-29T20:22:50.512964Z"}
{"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon: qemu+unix:///session?socket=/var/run/libvirt/virtqemud-sock","pos":"libvirt.go:524","timestamp":"2023-11-29T20:22:50.513503Z"}
{"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon failed: virError(Code=38, Domain=7, Message='Failed to connect socket to '/var/run/libvirt/virtqemud-sock': No such file or directory')","pos":"libvirt.go:532","timestamp":"2023-11-29T20:22:50.513805Z"}
{"component":"virt-launcher","level":"info","msg":"libvirt version: 9.0.0, package: 3.el9 ([email protected], 2023-02-01-12:58:56, )","subcomponent":"libvirt","thread":"48","timestamp":"2023-11-29T20:22:50.523000Z"}
{"component":"virt-launcher","level":"info","msg":"hostname: testvm","subcomponent":"libvirt","thread":"48","timestamp":"2023-11-29T20:22:50.523000Z"}
{"component":"virt-launcher","level":"error","msg":"Unable to open /dev/kvm: Permission denied","pos":"virHostCPUGetCPUID:1422","subcomponent":"libvirt","thread":"48","timestamp":"2023-11-29T20:22:50.523000Z"}
{"component":"virt-launcher","level":"error","msg":"internal error: Unable to get session bus connection: Cannot spawn a message bus without a machine-id: Unable to load /var/lib/dbus/machine-id or /etc/machine-id: Failed to open file “/var/lib/dbus/machine-id”: No such file or directory","pos":"virGDBusGetSessionBus:126","subcomponent":"libvirt","thread":"48","timestamp":"2023-11-29T20:22:50.524000Z"}
{"component":"virt-launcher","level":"error","msg":"internal error: Unable to get system bus connection: Could not connect: No such file or directory","pos":"virGDBusGetSystemBus:99","subcomponent":"libvirt","thread":"48","timestamp":"2023-11-29T20:22:50.524000Z"}
{"component":"virt-launcher","level":"info","msg":"Connected to libvirt daemon","pos":"libvirt.go:540","timestamp":"2023-11-29T20:22:51.017092Z"}
{"component":"virt-launcher","level":"info","msg":"Registered libvirt event notify callback","pos":"client.go:539","timestamp":"2023-11-29T20:22:51.022126Z"}
{"component":"virt-launcher","level":"info","msg":"Marked as ready","pos":"virt-launcher.go:75","timestamp":"2023-11-29T20:22:51.022531Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Executing PreStartHook on VMI pod environment","name":"testvm","namespace":"default","pos":"manager.go:623","timestamp":"2023-11-29T20:22:52.452199Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Starting PreCloudInitIso hook","name":"testvm","namespace":"default","pos":"manager.go:644","timestamp":"2023-11-29T20:22:52.452250Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","level":"info","msg":"Found nameservers in /etc/resolv.conf: \ufffd\u001d\u0008\n","pos":"network.go:293","timestamp":"2023-11-29T20:22:52.452814Z"}
{"component":"virt-launcher","level":"info","msg":"Found search domains in /etc/resolv.conf: default.svc.cluster.local svc.cluster.local cluster.local","pos":"network.go:294","timestamp":"2023-11-29T20:22:52.452838Z"}
{"component":"virt-launcher","level":"info","msg":"Starting SingleClientDHCPServer","pos":"server.go:65","timestamp":"2023-11-29T20:22:52.452889Z"}
{"component":"virt-launcher","level":"info","msg":"Driver cache mode for /var/run/kubevirt-ephemeral-disks/disk-data/containerdisk/disk.qcow2 set to none","pos":"converter.go:472","timestamp":"2023-11-29T20:22:52.460633Z"}
{"component":"virt-launcher","level":"info","msg":"Driver cache mode for /var/run/kubevirt-ephemeral-disks/cloud-init-data/default/testvm/noCloud.iso set to none","pos":"converter.go:472","timestamp":"2023-11-29T20:22:52.463449Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Domain XML generated. Base64 dump
....
.... <snip>
....
{"component":"virt-launcher","level":"info","msg":"Successfully connected to domain notify socket at /var/run/kubevirt/domain-notify-pipe.sock","pos":"client.go:170","timestamp":"2023-11-29T20:22:53.119577Z"}
{"component":"virt-launcher","level":"info","msg":"Domain name event: default_testvm","pos":"client.go:423","timestamp":"2023-11-29T20:22:53.123481Z"}
{"component":"virt-launcher","level":"info","msg":"Monitoring loop: rate 1s start timeout 4m31s","pos":"monitor.go:187","timestamp":"2023-11-29T20:22:53.125361Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Domain defined.","name":"testvm","namespace":"default","pos":"manager.go:1002","timestamp":"2023-11-29T20:22:53.144049Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","level":"info","msg":"DomainLifecycle event Domain event=\"defined\" detail=\"updated\" with event id 0 reason 1 received","pos":"client.go:465","timestamp":"2023-11-29T20:22:53.144056Z"}
{"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Shutoff(5):Unknown(0)","pos":"client.go:296","timestamp":"2023-11-29T20:22:53.149434Z"}
{"component":"virt-launcher","level":"info","msg":"Domain name event: default_testvm","pos":"client.go:423","timestamp":"2023-11-29T20:22:53.151159Z"}
{"component":"virt-launcher","level":"info","msg":"generated nocloud iso file /var/run/kubevirt-ephemeral-disks/cloud-init-data/default/testvm/noCloud.iso","pos":"cloud-init.go:674","timestamp":"2023-11-29T20:22:53.258158Z"}
{"component":"virt-launcher","level":"info","msg":"GuestAgentLifecycle event state 2 with reason 1 received","pos":"client.go:522","timestamp":"2023-11-29T20:22:53.314590Z"}
{"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Paused(3):StartingUp(11)","pos":"client.go:296","timestamp":"2023-11-29T20:22:53.315954Z"}
{"component":"virt-launcher","level":"info","msg":"Domain name event: default_testvm","pos":"client.go:423","timestamp":"2023-11-29T20:22:53.316688Z"}
{"component":"virt-launcher","level":"info","msg":"DomainLifecycle event Domain event=\"resumed\" detail=\"unpaused\" with event id 4 reason 0 received","pos":"client.go:465","timestamp":"2023-11-29T20:22:53.486742Z"}
{"component":"virt-launcher","level":"info","msg":"DomainLifecycle event Domain event=\"started\" detail=\"booted\" with event id 2 reason 0 received","pos":"client.go:465","timestamp":"2023-11-29T20:22:53.487854Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Domain started.","name":"testvm","namespace":"default","pos":"manager.go:1030","timestamp":"2023-11-29T20:22:53.488669Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Running(1):Unknown(1)","pos":"client.go:296","timestamp":"2023-11-29T20:22:53.489592Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Synced vmi","name":"testvm","namespace":"default","pos":"server.go:208","timestamp":"2023-11-29T20:22:53.489835Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","level":"info","msg":"Domain name event: default_testvm","pos":"client.go:423","timestamp":"2023-11-29T20:22:53.490357Z"}
{"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Running(1):Unknown(1)","pos":"client.go:296","timestamp":"2023-11-29T20:22:53.491293Z"}
{"component":"virt-launcher","level":"info","msg":"Domain name event: default_testvm","pos":"client.go:423","timestamp":"2023-11-29T20:22:53.492115Z"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Synced vmi","name":"testvm","namespace":"default","pos":"server.go:208","timestamp":"2023-11-29T20:22:53.534287Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Synced vmi","name":"testvm","namespace":"default","pos":"server.go:208","timestamp":"2023-11-29T20:22:53.555245Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","kind":"","level":"info","msg":"Synced vmi","name":"testvm","namespace":"default","pos":"server.go:208","timestamp":"2023-11-29T20:22:53.605969Z","uid":"969132b2-32a4-47a1-b0d3-d8e970b328bc"}
{"component":"virt-launcher","level":"info","msg":"Found PID for default_testvm: 86","pos":"monitor.go:148","timestamp":"2023-11-29T20:22:54.125751Z"}

How did you solve your problem ?My problem still exists to this day

kubernetes 1.23.6 containerd 1.6 kubernetes is binary install

mansoncui avatar Feb 28 '24 07:02 mansoncui