using minikube with qemu driver should allow "dirty" qemu builds - Invalid character(s) found in patch number

[schwichtgit]

What Happened?

If one builds qemu locally for example on MacOS,

$ /usr/local/bin/qemu-system-aarch64 --version
QEMU emulator version 7.1.50 (v7.1.0-406-g6160d8ff81-dirty)
Copyright (c) 2003-2022 Fabrice Bellard and the QEMU Project developers

qemu has additional output that trips the minikube qemu driver version parser.

for example

minikube start --memory=20480 --cpus=6  --disk-size=100g  --service-cluster-ip-range=10.64.0.0/16 --driver=qemu --qemu-firmware-path=/usr/local/share/qemu/edk2-aarch64-code.fd  --cni=calico

leads to

😄  minikube v1.27.1 on Darwin 12.6 (arm64)
✨  Using the qemu2 (experimental) driver based on user configuration
❗  The default network for QEMU will change from 'user' to 'socket_vmnet' in a future release
❗  You are using the QEMU driver without a dedicated network, which doesn't support `minikube service` & `minikube tunnel` commands.
To try the experimental dedicated network see: https://minikube.sigs.k8s.io/docs/drivers/qemu/#networking
👍  Starting control plane node minikube in cluster minikube
💾  Downloading Kubernetes v1.25.2 preload ...
    > preloaded-images-k8s-v18-v1...:  320.84 MiB / 320.84 MiB  100.00% 4.11 Mi
🔥  Creating qemu2 VM (CPUs=6, Memory=20480MB, Disk=102400MB) ...
🤦  StartHost failed, but will try again: config: Invalid character(s) found in patch number "50 (v7.1.0"
🔥  Creating qemu2 VM (CPUs=6, Memory=20480MB, Disk=102400MB) ...
😿  Failed to start qemu2 VM. Running "minikube delete" may fix it: config: Invalid character(s) found in patch number "50 (v7.1.0"

❌  Exiting due to GUEST_PROVISION: Failed to start host: config: Invalid character(s) found in patch number "50 (v7.1.0"

### Attach the log file

*
* ==> Audit <==
* 
*
|--------------|-----------------------------------------------------------------|----------|-------|---------|---------------------|---------------------|
|   Command    |                              Args                               | Profile  | User  | Version |     Start Time      |      End Time       |
|--------------|-----------------------------------------------------------------|----------|-------|---------|---------------------|---------------------|
| start        | --memory=20480 --cpus=6 --disk-size=100g                        | minikube | frank | v1.27.1 | 11 Oct 22 15:28 EDT |                     |
|              | --service-cluster-ip-range=10.64.0.0/16 --driver=qemu           |          |       |         |                     |                     |
|              | --qemu-firmware-path=/usr/local/share/qemu/edk2-aarch64-code.fd |          |       |         |                     |                     |
|              | --cni=calico                                                    |          |       |         |                     |                     |
|--------------|-----------------------------------------------------------------|----------|-------|---------|---------------------|---------------------|

*
* ==> Last Start <==
* Log file created at: 2022/10/11 15:28:00
Running on machine: MacBook-Pro
Binary: Built with gc go1.19.1 for darwin/arm64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I1011 15:28:00.734959   99202 out.go:296] Setting OutFile to fd 1 ...
I1011 15:28:00.735127   99202 out.go:348] isatty.IsTerminal(1) = true
I1011 15:28:00.735129   99202 out.go:309] Setting ErrFile to fd 2...
I1011 15:28:00.735131   99202 out.go:348] isatty.IsTerminal(2) = true
I1011 15:28:00.735202   99202 root.go:333] Updating PATH: /Users/frank/.minikube/bin
I1011 15:28:00.735960   99202 out.go:303] Setting JSON to false
I1011 15:28:00.759118   99202 start.go:116] hostinfo: {"hostname":"MacBook-Pro.local","uptime":1204358,"bootTime":1664312122,"procs":774,"os":"darwin","platform":"darwin","platformFamily":"Standalone Workstation","platformVersion":"12.6","kernelVersion":"21.6.0","kernelArch":"arm64","virtualizationSystem":"","virtualizationRole":"","hostId":"be74aed9-88b5-5d54-9547-08d468460add"}
W1011 15:28:00.759215   99202 start.go:124] gopshost.Virtualization returned error: not implemented yet
I1011 15:28:00.788675   99202 out.go:177] 😄  minikube v1.27.1 on Darwin 12.6 (arm64)
I1011 15:28:00.849030   99202 notify.go:220] Checking for updates...
I1011 15:28:00.849424   99202 driver.go:362] Setting default libvirt URI to qemu:///system
I1011 15:28:00.869945   99202 out.go:177] ✨  Using the qemu2 (experimental) driver based on user configuration
I1011 15:28:00.939486   99202 start.go:282] selected driver: qemu2
I1011 15:28:00.939520   99202 start.go:808] validating driver "qemu2" against <nil>
I1011 15:28:00.939560   99202 start.go:819] status for qemu2: {Installed:true Healthy:true Running:true NeedsImprovement:false Error:<nil> Reason: Fix: Doc: Version:}
I1011 15:28:00.943489   99202 start_flags.go:303] no existing cluster config was found, will generate one from the flags
W1011 15:28:00.943597   99202 out.go:239] ❗  The default network for QEMU will change from 'user' to 'socket_vmnet' in a future release
W1011 15:28:00.943622   99202 out.go:239] ❗  You are using the QEMU driver without a dedicated network, which doesn't support `minikube service` & `minikube tunnel` commands.
To try the experimental dedicated network see: https://minikube.sigs.k8s.io/docs/drivers/qemu/#networking
I1011 15:28:00.943757   99202 start_flags.go:867] Wait components to verify : map[apiserver:true system_pods:true]
I1011 15:28:00.943792   99202 cni.go:95] Creating CNI manager for "calico"
I1011 15:28:00.943801   99202 start_flags.go:312] Found "Calico" CNI - setting NetworkPlugin=cni
I1011 15:28:00.943814   99202 start_flags.go:317] config:
{Name:minikube KeepContext:false EmbedCerts:false MinikubeISO: KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.35@sha256:e6f9b2700841634f3b94907f9cfa6785ca4409ef8e428a0322c1781e809d311b Memory:20480 CPUs:6 DiskSize:102400 VMDriver: Driver:qemu2 HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[] ContainerVolumeMounts:[] InsecureRegistry:[] RegistryMirror:[] HostOnlyCIDR:192.168.59.1/24 HypervVirtualSwitch: HypervUseExternalSwitch:false HypervExternalAdapter: KVMNetwork:default KVMQemuURI:qemu:///system KVMGPU:false KVMHidden:false KVMNUMACount:1 APIServerPort:0 DockerOpt:[] DisableDriverMounts:false NFSShare:[] NFSSharesRoot:/nfsshares UUID: NoVTXCheck:false DNSProxy:false HostDNSResolver:true HostOnlyNicType:virtio NatNicType:virtio SSHIPAddress: SSHUser:root SSHKey: SSHPort:22 KubernetesConfig:{KubernetesVersion:v1.25.2 ClusterName:minikube Namespace:default APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin:cni FeatureGates: ServiceCIDR:10.64.0.0/16 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: CustomIngressCert: RegistryAliases: ExtraOptions:[] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI:calico NodeIP: NodePort:8443 NodeName:} Nodes:[] Addons:map[] CustomAddonImages:map[] CustomAddonRegistries:map[] VerifyComponents:map[apiserver:true system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[] ListenAddress: Network:user Subnet: MultiNodeRequested:false ExtraDisks:0 CertExpiration:26280h0m0s Mount:false MountString:/Users:/minikube-host Mount9PVersion:9p2000.L MountGID:docker MountIP: MountMSize:262144 MountOptions:[] MountPort:0 MountType:9p MountUID:docker BinaryMirror: DisableOptimizations:false DisableMetrics:false CustomQemuFirmwarePath:/usr/local/share/qemu/edk2-aarch64-code.fd SocketVMnetClientPath:/opt/socket_vmnet/bin/socket_vmnet_client SocketVMnetPath:/var/run/socket_vmnet}
I1011 15:28:00.944329   99202 iso.go:124] acquiring lock: {Name:mk3580fba4c134f070705a92e99661d6dbf863a2 Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I1011 15:28:01.056429   99202 out.go:177] 👍  Starting control plane node minikube in cluster minikube
I1011 15:28:01.092902   99202 preload.go:132] Checking if preload exists for k8s version v1.25.2 and runtime docker
I1011 15:28:01.627709   99202 preload.go:119] Found remote preload: https://storage.googleapis.com/minikube-preloaded-volume-tarballs/v18/v1.25.2/preloaded-images-k8s-v18-v1.25.2-docker-overlay2-arm64.tar.lz4
I1011 15:28:01.627756   99202 cache.go:57] Caching tarball of preloaded images
I1011 15:28:01.628595   99202 preload.go:132] Checking if preload exists for k8s version v1.25.2 and runtime docker
I1011 15:28:01.674826   99202 out.go:177] 💾  Downloading Kubernetes v1.25.2 preload ...
I1011 15:28:01.703544   99202 preload.go:238] getting checksum for preloaded-images-k8s-v18-v1.25.2-docker-overlay2-arm64.tar.lz4 ...
I1011 15:28:01.967693   99202 download.go:101] Downloading: https://storage.googleapis.com/minikube-preloaded-volume-tarballs/v18/v1.25.2/preloaded-images-k8s-v18-v1.25.2-docker-overlay2-arm64.tar.lz4?checksum=md5:cff4f49977db5c796b271e411b9aa28c -> /Users/frank/.minikube/cache/preloaded-tarball/preloaded-images-k8s-v18-v1.25.2-docker-overlay2-arm64.tar.lz4
I1011 15:29:21.422750   99202 preload.go:249] saving checksum for preloaded-images-k8s-v18-v1.25.2-docker-overlay2-arm64.tar.lz4 ...
I1011 15:29:21.422894   99202 preload.go:256] verifying checksum of /Users/frank/.minikube/cache/preloaded-tarball/preloaded-images-k8s-v18-v1.25.2-docker-overlay2-arm64.tar.lz4 ...
I1011 15:29:22.112449   99202 cache.go:60] Finished verifying existence of preloaded tar for  v1.25.2 on docker
I1011 15:29:22.112668   99202 profile.go:148] Saving config to /Users/frank/.minikube/profiles/minikube/config.json ...
I1011 15:29:22.112683   99202 lock.go:35] WriteFile acquiring /Users/frank/.minikube/profiles/minikube/config.json: {Name:mkd605eed0cccf9d2eae23848a4eaf1373f0a80a Clock:{} Delay:500ms Timeout:1m0s Cancel:<nil>}
I1011 15:29:22.112955   99202 cache.go:208] Successfully downloaded all kic artifacts
I1011 15:29:22.113015   99202 start.go:364] acquiring machines lock for minikube: {Name:mkb05d28032566e31afb636e6eece940d9ea4d4d Clock:{} Delay:500ms Timeout:13m0s Cancel:<nil>}
I1011 15:29:22.113079   99202 start.go:368] acquired machines lock for "minikube" in 60.209µs
I1011 15:29:22.113096   99202 start.go:93] Provisioning new machine with config: &{Name:minikube KeepContext:false EmbedCerts:false MinikubeISO:https://storage.googleapis.com/minikube/iso/minikube-v1.27.0-arm64.iso KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.35@sha256:e6f9b2700841634f3b94907f9cfa6785ca4409ef8e428a0322c1781e809d311b Memory:20480 CPUs:6 DiskSize:102400 VMDriver: Driver:qemu2 HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[] ContainerVolumeMounts:[] InsecureRegistry:[] RegistryMirror:[] HostOnlyCIDR:192.168.59.1/24 HypervVirtualSwitch: HypervUseExternalSwitch:false HypervExternalAdapter: KVMNetwork:default KVMQemuURI:qemu:///system KVMGPU:false KVMHidden:false KVMNUMACount:1 APIServerPort:0 DockerOpt:[] DisableDriverMounts:false NFSShare:[] NFSSharesRoot:/nfsshares UUID: NoVTXCheck:false DNSProxy:false HostDNSResolver:true HostOnlyNicType:virtio NatNicType:virtio SSHIPAddress: SSHUser:root SSHKey: SSHPort:22 KubernetesConfig:{KubernetesVersion:v1.25.2 ClusterName:minikube Namespace:default APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin:cni FeatureGates: ServiceCIDR:10.64.0.0/16 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: CustomIngressCert: RegistryAliases: ExtraOptions:[] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI:calico NodeIP: NodePort:8443 NodeName:} Nodes:[{Name: IP: Port:8443 KubernetesVersion:v1.25.2 ContainerRuntime:docker ControlPlane:true Worker:true}] Addons:map[] CustomAddonImages:map[] CustomAddonRegistries:map[] VerifyComponents:map[apiserver:true system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[] ListenAddress: Network:user Subnet: MultiNodeRequested:false ExtraDisks:0 CertExpiration:26280h0m0s Mount:false MountString:/Users:/minikube-host Mount9PVersion:9p2000.L MountGID:docker MountIP: MountMSize:262144 MountOptions:[] MountPort:0 MountType:9p MountUID:docker BinaryMirror: DisableOptimizations:false DisableMetrics:false CustomQemuFirmwarePath:/usr/local/share/qemu/edk2-aarch64-code.fd SocketVMnetClientPath:/opt/socket_vmnet/bin/socket_vmnet_client SocketVMnetPath:/var/run/socket_vmnet} &{Name: IP: Port:8443 KubernetesVersion:v1.25.2 ContainerRuntime:docker ControlPlane:true Worker:true}
I1011 15:29:22.113129   99202 start.go:125] createHost starting for "" (driver="qemu2")
I1011 15:29:22.162160   99202 out.go:204] 🔥  Creating qemu2 VM (CPUs=6, Memory=20480MB, Disk=102400MB) ...
I1011 15:29:22.232144   99202 start.go:128] duration metric: createHost completed in 118.989209ms
I1011 15:29:22.232156   99202 start.go:83] releasing machines lock for "minikube", held for 119.074542ms
W1011 15:29:22.232165   99202 start.go:603] error starting host: config: Invalid character(s) found in patch number "50 (v7.1.0"
I1011 15:29:22.232277   99202 cli_runner.go:164] Run: docker container inspect minikube --format={{.State.Status}}
W1011 15:29:22.403522   99202 cli_runner.go:211] docker container inspect minikube --format={{.State.Status}} returned with exit code 1
I1011 15:29:22.403570   99202 delete.go:46] couldn't inspect container "minikube" before deleting: unknown state "minikube": docker container inspect minikube --format={{.State.Status}}: exit status 1
stdout:


stderr:
Error: No such container: minikube
I1011 15:29:22.404621   99202 cli_runner.go:164] Run: podman container inspect minikube --format={{.State.Status}}
W1011 15:29:22.642777   99202 cli_runner.go:211] podman container inspect minikube --format={{.State.Status}} returned with exit code 125
I1011 15:29:22.642820   99202 delete.go:46] couldn't inspect container "minikube" before deleting: unknown state "minikube": podman container inspect minikube --format={{.State.Status}}: exit status 125
stdout:

stderr:
Error: inspecting object: no such container "minikube"
W1011 15:29:22.642854   99202 start.go:608] delete host: Docker machine "minikube" does not exist. Use "docker-machine ls" to list machines. Use "docker-machine create" to add a new one.
W1011 15:29:22.643020   99202 out.go:239] 🤦  StartHost failed, but will try again: config: Invalid character(s) found in patch number "50 (v7.1.0"
I1011 15:29:22.643040   99202 start.go:618] Will try again in 5 seconds ...
I1011 15:29:27.643782   99202 start.go:364] acquiring machines lock for minikube: {Name:mkb05d28032566e31afb636e6eece940d9ea4d4d Clock:{} Delay:500ms Timeout:13m0s Cancel:<nil>}
I1011 15:29:27.643971   99202 start.go:368] acquired machines lock for "minikube" in 131.375µs
I1011 15:29:27.643990   99202 start.go:93] Provisioning new machine with config: &{Name:minikube KeepContext:false EmbedCerts:false MinikubeISO:https://storage.googleapis.com/minikube/iso/minikube-v1.27.0-arm64.iso KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.35@sha256:e6f9b2700841634f3b94907f9cfa6785ca4409ef8e428a0322c1781e809d311b Memory:20480 CPUs:6 DiskSize:102400 VMDriver: Driver:qemu2 HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[] ContainerVolumeMounts:[] InsecureRegistry:[] RegistryMirror:[] HostOnlyCIDR:192.168.59.1/24 HypervVirtualSwitch: HypervUseExternalSwitch:false HypervExternalAdapter: KVMNetwork:default KVMQemuURI:qemu:///system KVMGPU:false KVMHidden:false KVMNUMACount:1 APIServerPort:0 DockerOpt:[] DisableDriverMounts:false NFSShare:[] NFSSharesRoot:/nfsshares UUID: NoVTXCheck:false DNSProxy:false HostDNSResolver:true HostOnlyNicType:virtio NatNicType:virtio SSHIPAddress: SSHUser:root SSHKey: SSHPort:22 KubernetesConfig:{KubernetesVersion:v1.25.2 ClusterName:minikube Namespace:default APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin:cni FeatureGates: ServiceCIDR:10.64.0.0/16 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: CustomIngressCert: RegistryAliases: ExtraOptions:[] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI:calico NodeIP: NodePort:8443 NodeName:} Nodes:[{Name: IP: Port:8443 KubernetesVersion:v1.25.2 ContainerRuntime:docker ControlPlane:true Worker:true}] Addons:map[] CustomAddonImages:map[] CustomAddonRegistries:map[] VerifyComponents:map[apiserver:true system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[] ListenAddress: Network:user Subnet: MultiNodeRequested:false ExtraDisks:0 CertExpiration:26280h0m0s Mount:false MountString:/Users:/minikube-host Mount9PVersion:9p2000.L MountGID:docker MountIP: MountMSize:262144 MountOptions:[] MountPort:0 MountType:9p MountUID:docker BinaryMirror: DisableOptimizations:false DisableMetrics:false CustomQemuFirmwarePath:/usr/local/share/qemu/edk2-aarch64-code.fd SocketVMnetClientPath:/opt/socket_vmnet/bin/socket_vmnet_client SocketVMnetPath:/var/run/socket_vmnet} &{Name: IP: Port:8443 KubernetesVersion:v1.25.2 ContainerRuntime:docker ControlPlane:true Worker:true}
I1011 15:29:27.644192   99202 start.go:125] createHost starting for "" (driver="qemu2")
I1011 15:29:27.688496   99202 out.go:204] 🔥  Creating qemu2 VM (CPUs=6, Memory=20480MB, Disk=102400MB) ...
I1011 15:29:27.722913   99202 start.go:128] duration metric: createHost completed in 78.704125ms
I1011 15:29:27.722924   99202 start.go:83] releasing machines lock for "minikube", held for 78.947583ms
W1011 15:29:27.723110   99202 out.go:239] 😿  Failed to start qemu2 VM. Running "minikube delete" may fix it: config: Invalid character(s) found in patch number "50 (v7.1.0"
I1011 15:29:27.773741   99202 out.go:177]
W1011 15:29:27.799666   99202 out.go:239] ❌  Exiting due to GUEST_PROVISION: Failed to start host: config: Invalid character(s) found in patch number "50 (v7.1.0"
W1011 15:29:27.799685   99202 out.go:239]
W1011 15:29:27.800294   99202 out.go:239] ╭───────────────────────────────────────────────────────────────────────────────────────────╮
│                                                                                           │
│    😿  If the above advice does not help, please let us know:                             │
│    👉  https://github.com/kubernetes/minikube/issues/new/choose                           │
│                                                                                           │
│    Please run `minikube logs --file=logs.txt` and attach logs.txt to the GitHub issue.    │
│                                                                                           │
╰───────────────────────────────────────────────────────────────────────────────────────────╯
I1011 15:29:27.870277   99202 out.go:177]

*

Operating System

macOS (Default)

Driver

qemu2

[schwichtgit]

would you accept a PR with this patch to address this?

diff -Naur 1/pkg/minikube/registry/drvs/qemu2/qemu2.go 2/pkg/minikube/registry/drvs/qemu2/qemu2.go
--- 1/pkg/minikube/registry/drvs/qemu2/qemu2.go	2022-09-26 15:25:12.469383191 -0400
+++ 2/pkg/minikube/registry/drvs/qemu2/qemu2.go	2022-09-26 15:48:06.561167788 -0400
@@ -116,7 +116,7 @@
 	if err != nil {
 		return semver.Version{}, err
 	}
-	v := strings.Split(strings.TrimPrefix(string(rr), "QEMU emulator version "), "\n")[0]
+	v := strings.Fields(strings.Split(strings.TrimPrefix(string(rr), "QEMU emulator version "), "\n")[0])[0]
 	return semver.Make(v)
 }

[spowelljr]

would you accept a PR with this patch to address this?

Hi @schwichtgit, yes, feel free to make a PR and we can get this fixed. My recommendation is to remove strings.Split as it's redundant now that you're grabbing the first value of strings.Fields.

[k8s-triage-robot]

The Kubernetes project currently lacks enough contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

• After 90d of inactivity, lifecycle/stale is applied
• After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
• After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

• Mark this issue or PR as fresh with /remove-lifecycle stale
• Mark this issue or PR as rotten with /lifecycle rotten
• Close this issue or PR with /close
• Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle stale

[k8s-triage-robot]

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues.

This bot triages un-triaged issues according to the following rules:

• After 90d of inactivity, lifecycle/stale is applied
• After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
• After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

• Mark this issue as fresh with /remove-lifecycle rotten
• Close this issue with /close
• Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle rotten

[schwichtgit]

I have (finally) filed PR18229