Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
mansoncui opened this issue Oct 22, 2023 · 33 comments
Labels

Comments

@mansoncui
Copy link

mansoncui commented Oct 22, 2023

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
@alicefr
Copy link
Member

alicefr commented Oct 24, 2023

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

@mansoncui
Copy link
Author

image 硬件虚拟化已经开启了

@mansoncui
Copy link
Author

image

@vasiliy-ul
Copy link
Contributor

vasiliy-ul commented Oct 25, 2023

This looks similar to #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.

@mansoncui
Copy link
Author

image

v1.0.0 same error reported

@vasiliy-ul
Copy link
Contributor

Is it Minikube / Kind or some other Kubernetes distro?

@mansoncui
Copy link
Author

kubernetes binary install

@vasiliy-ul
Copy link
Contributor

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

@mansoncui
Copy link
Author

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 (builder@centos.org, 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"}

@vasiliy-ul
Copy link
Contributor

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.

@vsundarraj-px
Copy link

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.

@vasiliy-ul
Copy link
Contributor

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

@vsundarraj-px
Copy link

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 (builder@centos.org, 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.

@vasiliy-ul
Copy link
Contributor

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?

@vsundarraj-px
Copy link

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

@vasiliy-ul
Copy link
Contributor

@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.

@vsundarraj-px
Copy link

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
Copy link

@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.

@vasiliy-ul
Copy link
Contributor

@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?

@vsundarraj-px
Copy link

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 (builder@centos.org, 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 (builder@centos.org, 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=`

@vasiliy-ul
Copy link
Contributor

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?

@vsundarraj-px
Copy link

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
Copy link

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

@vasiliy-ul
Copy link
Contributor

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.

@scog
Copy link

scog commented Nov 29, 2023

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 (builder@centos.org, 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 (builder@centos.org, 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"}

@openqt
Copy link

openqt commented Nov 30, 2023

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

@CharlesQQ
Copy link

I meet the same problem

@caijian76
Copy link

caijian76 commented Jan 31, 2024

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

@EdDev
Copy link
Member

EdDev commented Feb 16, 2024

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.

@mansoncui
Copy link
Author

任何更新,我看到 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.yaml`testvm`)
  • 硬件配置:裸机,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.yaml`testvm` )

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 (builder@centos.org, 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 (builder@centos.org, 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

@jiangxiaobin96
Copy link

I use kubevirt v1.2 and still meet the same issue. Is there any solution now?

@fabiand
Copy link
Member

fabiand commented Apr 24, 2024

Please provide cat /etc/os-release of the host.
Please provide lscpu of the host.

How did you deploy KubeVirt?

@jiangxiaobin96
Copy link

Thanks for your reply. The Permission denied has solved by chmod 777 /dev/kvm, but I met the new error.

  • error of pod/virt-launcher-testvm-2dskd
{"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":"2024-04-24T17:22:50.394000Z"}
{"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":"2024-04-24T17:22:50.394000Z"}
{"component":"virt-launcher-monitor","level":"error","msg":"dirty virt-launcher shutdown: exit-code 2","pos":"virt-launcher-monitor.go:143","timestamp":"2024-04-24T17:27:53.868555Z"}
  • cluster information
kubevirt       pod/virt-api-56fbd84dd5-b6tdd              1/1     Running   0          8h
kubevirt       pod/virt-api-56fbd84dd5-zh7qz              1/1     Running   0          8h
kubevirt       pod/virt-controller-7f68fbd688-8gk2b       1/1     Running   0          8h
kubevirt       pod/virt-controller-7f68fbd688-rmlsz       1/1     Running   0          8h
kubevirt       pod/virt-handler-k4dns                     1/1     Running   0          8h
kubevirt       pod/virt-handler-zgkjq                     1/1     Running   0          8h
kubevirt       pod/virt-launcher-testvm-2dskd             0/2     Error     0          7h57m
kubevirt       pod/virt-operator-8b8d65f8f-2wtnr          1/1     Running   0          8h
kubevirt       pod/virt-operator-8b8d65f8f-6ps6l          1/1     Running   0          8h
  • host information
$ cat /etc/os-release
NAME="Ubuntu"
VERSION="20.04.6 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.6 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal
  • kubevirt deployment
wget https://github.com/kubevirt/kubevirt/releases/download/v1.2.0/kubevirt-operator.yaml
wget https://github.com/kubevirt/kubevirt/releases/download/v1.2.0/kubevirt-cr.yaml

sudo kubectl apply -f kubevirt-operator.yaml --kubeconfig ~/.kube/config
sudo kubectl apply -f kubevirt-cr.yaml --kubeconfig ~/.kube/config
  • vm deployment
sudo kubectl apply -f vm.yaml --kubeconfig ~/.kube/config
cat vm.yaml
---
apiVersion: kubevirt.io/v1
kind: VirtualMachineInstance
metadata:
  labels:
    kubevirt.io/size: small
    kubevirt.io/domain: testvm
    debugLogs: "true"
    logVerbosity: "6"
  name: testvm
  namespace: kubevirt
spec:
  domain:
    devices:
      disks:
        - name: containerdisk
          disk:
            bus: virtio
      interfaces:
      - name: default
        masquerade: {}
    resources:
      requests:
        memory: 64M
  networks:
  - name: default
    pod: {}
  volumes:
    - name: containerdisk
      containerDisk:
        image: docker.io/kubevirt/cirros-registry-disk-demo

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

12 participants