=== RUN TestStartStop/group/no-preload/serial/SecondStart
start_stop_delete_test.go:256: (dbg) Run: out/minikube-darwin-amd64 start -p no-preload-540000 --memory=2200 --alsologtostderr --wait=true --preload=false --driver=hyperkit --kubernetes-version=v1.27.3
E0731 04:23:43.795484 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/ingress-addon-legacy-518000/client.crt: no such file or directory
E0731 04:23:48.258636 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/enable-default-cni-967000/client.crt: no such file or directory
E0731 04:23:51.485053 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:23:51.491499 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:23:51.502146 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:23:51.523483 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:23:51.564948 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:23:51.646040 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:23:51.807712 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:23:52.129869 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:23:52.770927 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:23:54.051680 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:23:56.613843 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
E0731 04:24:01.735601 1454 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/kubenet-967000/client.crt: no such file or directory
start_stop_delete_test.go:256: (dbg) Non-zero exit: out/minikube-darwin-amd64 start -p no-preload-540000 --memory=2200 --alsologtostderr --wait=true --preload=false --driver=hyperkit --kubernetes-version=v1.27.3: exit status 90 (1m16.631059504s)
-- stdout --
* [no-preload-540000] minikube v1.31.1 on Darwin 13.4.1
- MINIKUBE_LOCATION=16969
- KUBECONFIG=/Users/jenkins/minikube-integration/16969-982/kubeconfig
- MINIKUBE_BIN=out/minikube-darwin-amd64
- MINIKUBE_SUPPRESS_DOCKER_PERFORMANCE=true
- MINIKUBE_HOME=/Users/jenkins/minikube-integration/16969-982/.minikube
- MINIKUBE_FORCE_SYSTEMD=
* Using the hyperkit driver based on existing profile
* Starting control plane node no-preload-540000 in cluster no-preload-540000
* Restarting existing hyperkit VM for "no-preload-540000" ...
-- /stdout --
** stderr **
I0731 04:23:41.080775 8087 out.go:296] Setting OutFile to fd 1 ...
I0731 04:23:41.080934 8087 out.go:343] TERM=,COLORTERM=, which probably does not support color
I0731 04:23:41.080939 8087 out.go:309] Setting ErrFile to fd 2...
I0731 04:23:41.080943 8087 out.go:343] TERM=,COLORTERM=, which probably does not support color
I0731 04:23:41.081115 8087 root.go:338] Updating PATH: /Users/jenkins/minikube-integration/16969-982/.minikube/bin
I0731 04:23:41.082567 8087 out.go:303] Setting JSON to false
I0731 04:23:41.101702 8087 start.go:128] hostinfo: {"hostname":"MacOS-Agent-4.local","uptime":3192,"bootTime":1690799429,"procs":401,"os":"darwin","platform":"darwin","platformFamily":"Standalone Workstation","platformVersion":"13.4.1","kernelVersion":"22.5.0","kernelArch":"x86_64","virtualizationSystem":"","virtualizationRole":"","hostId":"f2f27e25-cfda-5ffd-9706-e98286194e62"}
W0731 04:23:41.101803 8087 start.go:136] gopshost.Virtualization returned error: not implemented yet
I0731 04:23:41.122498 8087 out.go:177] * [no-preload-540000] minikube v1.31.1 on Darwin 13.4.1
I0731 04:23:41.166572 8087 notify.go:220] Checking for updates...
I0731 04:23:41.193387 8087 out.go:177] - MINIKUBE_LOCATION=16969
I0731 04:23:41.215017 8087 out.go:177] - KUBECONFIG=/Users/jenkins/minikube-integration/16969-982/kubeconfig
I0731 04:23:41.236337 8087 out.go:177] - MINIKUBE_BIN=out/minikube-darwin-amd64
I0731 04:23:41.258335 8087 out.go:177] - MINIKUBE_SUPPRESS_DOCKER_PERFORMANCE=true
I0731 04:23:41.279849 8087 out.go:177] - MINIKUBE_HOME=/Users/jenkins/minikube-integration/16969-982/.minikube
I0731 04:23:41.301209 8087 out.go:177] - MINIKUBE_FORCE_SYSTEMD=
I0731 04:23:41.323811 8087 config.go:182] Loaded profile config "no-preload-540000": Driver=hyperkit, ContainerRuntime=docker, KubernetesVersion=v1.27.3
I0731 04:23:41.324499 8087 main.go:141] libmachine: Found binary path at /Users/jenkins/workspace/out/docker-machine-driver-hyperkit
I0731 04:23:41.324546 8087 main.go:141] libmachine: Launching plugin server for driver hyperkit
I0731 04:23:41.332287 8087 main.go:141] libmachine: Plugin server listening at address 127.0.0.1:56212
I0731 04:23:41.332673 8087 main.go:141] libmachine: () Calling .GetVersion
I0731 04:23:41.333125 8087 main.go:141] libmachine: Using API Version 1
I0731 04:23:41.333135 8087 main.go:141] libmachine: () Calling .SetConfigRaw
I0731 04:23:41.333359 8087 main.go:141] libmachine: () Calling .GetMachineName
I0731 04:23:41.333542 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
I0731 04:23:41.333730 8087 driver.go:373] Setting default libvirt URI to qemu:///system
I0731 04:23:41.333968 8087 main.go:141] libmachine: Found binary path at /Users/jenkins/workspace/out/docker-machine-driver-hyperkit
I0731 04:23:41.334035 8087 main.go:141] libmachine: Launching plugin server for driver hyperkit
I0731 04:23:41.340684 8087 main.go:141] libmachine: Plugin server listening at address 127.0.0.1:56214
I0731 04:23:41.340995 8087 main.go:141] libmachine: () Calling .GetVersion
I0731 04:23:41.341331 8087 main.go:141] libmachine: Using API Version 1
I0731 04:23:41.341343 8087 main.go:141] libmachine: () Calling .SetConfigRaw
I0731 04:23:41.341531 8087 main.go:141] libmachine: () Calling .GetMachineName
I0731 04:23:41.341637 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
I0731 04:23:41.368961 8087 out.go:177] * Using the hyperkit driver based on existing profile
I0731 04:23:41.389987 8087 start.go:298] selected driver: hyperkit
I0731 04:23:41.390035 8087 start.go:898] validating driver "hyperkit" against &{Name:no-preload-540000 KeepContext:false EmbedCerts:false MinikubeISO:https://storage.googleapis.com/minikube/iso/minikube-v1.31.0-amd64.iso KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.40@sha256:8cadf23777709e43eca447c47a45f5a4635615129267ce025193040ec92a1631 Memory:2200 CPUs:2 DiskSize:20000 VMDriver: Driver:hyperkit 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.27.3 ClusterName:no-pre
load-540000 Namespace:default APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin:cni FeatureGates: ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: CustomIngressCert: RegistryAliases: ExtraOptions:[] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI: NodeIP: NodePort:8443 NodeName:} Nodes:[{Name: IP:192.168.64.41 Port:8443 KubernetesVersion:v1.27.3 ContainerRuntime:docker ControlPlane:true Worker:true}] Addons:map[dashboard:true default-storageclass:true metrics-server:true storage-provisioner:true] CustomAddonImages:map[MetricsScraper:registry.k8s.io/echoserver:1.4 MetricsServer:registry.k8s.io/echoserver:1.4] CustomAddonRegistries:map[MetricsServer:fake.domain] VerifyComponents:map[apiserver:true apps_running:true default_sa:true extra:true kubelet:true node_ready:true system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[] ListenAddress: Network: Subnet: MultiNodeReques
ted: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: SocketVMnetClientPath: SocketVMnetPath: StaticIP: SSHAuthSock: SSHAgentPID:0}
I0731 04:23:41.390263 8087 start.go:909] status for hyperkit: {Installed:true Healthy:true Running:true NeedsImprovement:false Error:<nil> Reason: Fix: Doc: Version:}
I0731 04:23:41.394164 8087 install.go:52] acquiring lock: {Name:mk4023283b30b374c3f04c8805d539e68824c0b8 Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0731 04:23:41.394267 8087 install.go:117] Validating docker-machine-driver-hyperkit, PATH=/Users/jenkins/minikube-integration/16969-982/.minikube/bin:/Users/jenkins/workspace/out/:/usr/bin:/bin:/usr/sbin:/sbin:/Users/jenkins/google-cloud-sdk/bin:/usr/local/bin/:/usr/local/go/bin/:/Users/jenkins/go/bin
I0731 04:23:41.400991 8087 install.go:137] /Users/jenkins/workspace/out/docker-machine-driver-hyperkit version is 1.31.1
I0731 04:23:41.404497 8087 install.go:79] stdout: /Users/jenkins/workspace/out/docker-machine-driver-hyperkit
I0731 04:23:41.404518 8087 install.go:81] /Users/jenkins/workspace/out/docker-machine-driver-hyperkit looks good
I0731 04:23:41.404772 8087 start_flags.go:919] Waiting for all components: map[apiserver:true apps_running:true default_sa:true extra:true kubelet:true node_ready:true system_pods:true]
I0731 04:23:41.404796 8087 cni.go:84] Creating CNI manager for ""
I0731 04:23:41.404808 8087 cni.go:158] "hyperkit" driver + "docker" container runtime found on kubernetes v1.24+, recommending bridge
I0731 04:23:41.404820 8087 start_flags.go:319] config:
{Name:no-preload-540000 KeepContext:false EmbedCerts:false MinikubeISO:https://storage.googleapis.com/minikube/iso/minikube-v1.31.0-amd64.iso KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.40@sha256:8cadf23777709e43eca447c47a45f5a4635615129267ce025193040ec92a1631 Memory:2200 CPUs:2 DiskSize:20000 VMDriver: Driver:hyperkit 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.27.3 ClusterName:no-preload-540000 Namespace:default APIServerName:minikubeCA APIServerNames:[] APIServer
IPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin:cni FeatureGates: ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: CustomIngressCert: RegistryAliases: ExtraOptions:[] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI: NodeIP: NodePort:8443 NodeName:} Nodes:[{Name: IP:192.168.64.41 Port:8443 KubernetesVersion:v1.27.3 ContainerRuntime:docker ControlPlane:true Worker:true}] Addons:map[dashboard:true default-storageclass:true metrics-server:true storage-provisioner:true] CustomAddonImages:map[MetricsScraper:registry.k8s.io/echoserver:1.4 MetricsServer:registry.k8s.io/echoserver:1.4] CustomAddonRegistries:map[MetricsServer:fake.domain] VerifyComponents:map[apiserver:true apps_running:true default_sa:true extra:true kubelet:true node_ready:true system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[] ListenAddress: Network: Subnet: MultiNodeRequested:false ExtraDisks:0 CertExpiration:26280h0m0s Mount:false MountString:/Users:/m
inikube-host Mount9PVersion:9p2000.L MountGID:docker MountIP: MountMSize:262144 MountOptions:[] MountPort:0 MountType:9p MountUID:docker BinaryMirror: DisableOptimizations:false DisableMetrics:false CustomQemuFirmwarePath: SocketVMnetClientPath: SocketVMnetPath: StaticIP: SSHAuthSock: SSHAgentPID:0}
I0731 04:23:41.404949 8087 iso.go:125] acquiring lock: {Name:mka2e15c7ab2d40446fa318540080de673de5a9d Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0731 04:23:41.425934 8087 out.go:177] * Starting control plane node no-preload-540000 in cluster no-preload-540000
I0731 04:23:41.446936 8087 preload.go:132] Checking if preload exists for k8s version v1.27.3 and runtime docker
I0731 04:23:41.447169 8087 profile.go:148] Saving config to /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/no-preload-540000/config.json ...
I0731 04:23:41.447280 8087 cache.go:107] acquiring lock: {Name:mk4e7ee1aa9b8b06bfb5f694fb937311022ab223 Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0731 04:23:41.447286 8087 cache.go:107] acquiring lock: {Name:mk63a3d801828cdd3fbf0b7c57dee43a71a104e1 Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0731 04:23:41.447360 8087 cache.go:107] acquiring lock: {Name:mk32130d063dc066fcd41606a33e84855ee4dc94 Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0731 04:23:41.447443 8087 cache.go:107] acquiring lock: {Name:mk5656f5efdb09160ce88d626690dc74e3156c35 Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0731 04:23:41.447514 8087 cache.go:115] /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/gcr.io/k8s-minikube/storage-provisioner_v5 exists
I0731 04:23:41.447582 8087 cache.go:96] cache image "gcr.io/k8s-minikube/storage-provisioner:v5" -> "/Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/gcr.io/k8s-minikube/storage-provisioner_v5" took 284.306µs
I0731 04:23:41.447613 8087 cache.go:80] save to tar file gcr.io/k8s-minikube/storage-provisioner:v5 -> /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/gcr.io/k8s-minikube/storage-provisioner_v5 succeeded
I0731 04:23:41.447531 8087 cache.go:107] acquiring lock: {Name:mk30ef828c19bf2380cdc659a86faef58dbde915 Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0731 04:23:41.447638 8087 cache.go:107] acquiring lock: {Name:mkd638bf6d45a54b56ad3c3350a558a35bbe9678 Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0731 04:23:41.447644 8087 cache.go:107] acquiring lock: {Name:mk62279e3d68118bbfba94e35e0884231bc1f11d Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0731 04:23:41.447727 8087 cache.go:115] /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/pause_3.9 exists
I0731 04:23:41.447754 8087 cache.go:96] cache image "registry.k8s.io/pause:3.9" -> "/Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/pause_3.9" took 357.543µs
I0731 04:23:41.448516 8087 cache.go:80] save to tar file registry.k8s.io/pause:3.9 -> /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/pause_3.9 succeeded
I0731 04:23:41.448536 8087 cache.go:115] /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-controller-manager_v1.27.3 exists
I0731 04:23:41.448563 8087 cache.go:96] cache image "registry.k8s.io/kube-controller-manager:v1.27.3" -> "/Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-controller-manager_v1.27.3" took 1.297904ms
I0731 04:23:41.448563 8087 cache.go:115] /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-apiserver_v1.27.3 exists
I0731 04:23:41.448589 8087 cache.go:80] save to tar file registry.k8s.io/kube-controller-manager:v1.27.3 -> /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-controller-manager_v1.27.3 succeeded
I0731 04:23:41.447729 8087 cache.go:107] acquiring lock: {Name:mkffcf84a1654fa0b63acdf3d016283a2fb5cba1 Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0731 04:23:41.448602 8087 cache.go:96] cache image "registry.k8s.io/kube-apiserver:v1.27.3" -> "/Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-apiserver_v1.27.3" took 1.312624ms
I0731 04:23:41.448637 8087 cache.go:80] save to tar file registry.k8s.io/kube-apiserver:v1.27.3 -> /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-apiserver_v1.27.3 succeeded
I0731 04:23:41.448761 8087 cache.go:115] /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/coredns/coredns_v1.10.1 exists
I0731 04:23:41.448787 8087 cache.go:96] cache image "registry.k8s.io/coredns/coredns:v1.10.1" -> "/Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/coredns/coredns_v1.10.1" took 1.243525ms
I0731 04:23:41.448814 8087 cache.go:80] save to tar file registry.k8s.io/coredns/coredns:v1.10.1 -> /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/coredns/coredns_v1.10.1 succeeded
I0731 04:23:41.448815 8087 cache.go:115] /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-scheduler_v1.27.3 exists
I0731 04:23:41.448870 8087 cache.go:96] cache image "registry.k8s.io/kube-scheduler:v1.27.3" -> "/Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-scheduler_v1.27.3" took 1.459737ms
I0731 04:23:41.448907 8087 cache.go:80] save to tar file registry.k8s.io/kube-scheduler:v1.27.3 -> /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-scheduler_v1.27.3 succeeded
I0731 04:23:41.448931 8087 cache.go:115] /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/etcd_3.5.7-0 exists
I0731 04:23:41.448959 8087 cache.go:115] /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-proxy_v1.27.3 exists
I0731 04:23:41.448974 8087 cache.go:96] cache image "registry.k8s.io/kube-proxy:v1.27.3" -> "/Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-proxy_v1.27.3" took 1.429974ms
I0731 04:23:41.448996 8087 cache.go:80] save to tar file registry.k8s.io/kube-proxy:v1.27.3 -> /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/kube-proxy_v1.27.3 succeeded
I0731 04:23:41.448976 8087 cache.go:96] cache image "registry.k8s.io/etcd:3.5.7-0" -> "/Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/etcd_3.5.7-0" took 1.338854ms
I0731 04:23:41.449019 8087 cache.go:80] save to tar file registry.k8s.io/etcd:3.5.7-0 -> /Users/jenkins/minikube-integration/16969-982/.minikube/cache/images/amd64/registry.k8s.io/etcd_3.5.7-0 succeeded
I0731 04:23:41.449032 8087 cache.go:87] Successfully saved all images to host disk.
I0731 04:23:41.449310 8087 start.go:365] acquiring machines lock for no-preload-540000: {Name:mka0fc018b4c9bb6a2e0207f313c5a6b05707bcb Clock:{} Delay:500ms Timeout:13m0s Cancel:<nil>}
I0731 04:23:41.449492 8087 start.go:369] acquired machines lock for "no-preload-540000" in 48.872µs
I0731 04:23:41.449528 8087 start.go:96] Skipping create...Using existing machine configuration
I0731 04:23:41.449549 8087 fix.go:54] fixHost starting:
I0731 04:23:41.450228 8087 main.go:141] libmachine: Found binary path at /Users/jenkins/workspace/out/docker-machine-driver-hyperkit
I0731 04:23:41.450253 8087 main.go:141] libmachine: Launching plugin server for driver hyperkit
I0731 04:23:41.457489 8087 main.go:141] libmachine: Plugin server listening at address 127.0.0.1:56216
I0731 04:23:41.457865 8087 main.go:141] libmachine: () Calling .GetVersion
I0731 04:23:41.458220 8087 main.go:141] libmachine: Using API Version 1
I0731 04:23:41.458230 8087 main.go:141] libmachine: () Calling .SetConfigRaw
I0731 04:23:41.458466 8087 main.go:141] libmachine: () Calling .GetMachineName
I0731 04:23:41.458572 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
I0731 04:23:41.458666 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetState
I0731 04:23:41.458753 8087 main.go:141] libmachine: (no-preload-540000) DBG | exe=/Users/jenkins/workspace/out/docker-machine-driver-hyperkit uid=0
I0731 04:23:41.458816 8087 main.go:141] libmachine: (no-preload-540000) DBG | hyperkit pid from json: 7873
I0731 04:23:41.459705 8087 main.go:141] libmachine: (no-preload-540000) DBG | hyperkit pid 7873 missing from process table
I0731 04:23:41.459733 8087 fix.go:102] recreateIfNeeded on no-preload-540000: state=Stopped err=<nil>
I0731 04:23:41.459748 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
W0731 04:23:41.459832 8087 fix.go:128] unexpected machine state, will restart: <nil>
I0731 04:23:41.481153 8087 out.go:177] * Restarting existing hyperkit VM for "no-preload-540000" ...
I0731 04:23:41.519219 8087 main.go:141] libmachine: (no-preload-540000) Calling .Start
I0731 04:23:41.519545 8087 main.go:141] libmachine: (no-preload-540000) DBG | exe=/Users/jenkins/workspace/out/docker-machine-driver-hyperkit uid=0
I0731 04:23:41.519623 8087 main.go:141] libmachine: (no-preload-540000) minikube might have been shutdown in an unclean way, the hyperkit pid file still exists: /Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/hyperkit.pid
I0731 04:23:41.521413 8087 main.go:141] libmachine: (no-preload-540000) DBG | hyperkit pid 7873 missing from process table
I0731 04:23:41.521431 8087 main.go:141] libmachine: (no-preload-540000) DBG | pid 7873 is in state "Stopped"
I0731 04:23:41.521460 8087 main.go:141] libmachine: (no-preload-540000) DBG | Removing stale pid file /Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/hyperkit.pid...
I0731 04:23:41.521573 8087 main.go:141] libmachine: (no-preload-540000) DBG | Using UUID 8638cdce-2f94-11ee-9783-149d997fca88
I0731 04:23:41.550811 8087 main.go:141] libmachine: (no-preload-540000) DBG | Generated MAC d6:ba:23:4e:ec:2
I0731 04:23:41.550840 8087 main.go:141] libmachine: (no-preload-540000) DBG | Starting with cmdline: loglevel=3 console=ttyS0 console=tty0 noembed nomodeset norestore waitusb=10 systemd.legacy_systemd_cgroup_controller=yes random.trust_cpu=on hw_rng_model=virtio base host=no-preload-540000
I0731 04:23:41.551029 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 DEBUG: hyperkit: Start &hyperkit.HyperKit{HyperKit:"/usr/local/bin/hyperkit", Argv0:"", StateDir:"/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000", VPNKitSock:"", VPNKitUUID:"", VPNKitPreferredIPv4:"", UUID:"8638cdce-2f94-11ee-9783-149d997fca88", Disks:[]hyperkit.Disk{(*hyperkit.RawDisk)(0xc0003ebb60)}, ISOImages:[]string{"/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/boot2docker.iso"}, VSock:false, VSockDir:"", VSockPorts:[]int(nil), VSockGuestCID:3, VMNet:true, Sockets9P:[]hyperkit.Socket9P(nil), Kernel:"/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/bzimage", Initrd:"/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/initrd", Bootrom:"", CPUs:2, Memory:2200, Console:1, Serials:[]hyperkit.Serial(nil), Pid:0, Arguments:[]string(nil), CmdLine:"", process:(*os.Proc
ess)(nil)}
I0731 04:23:41.551078 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 DEBUG: hyperkit: check &hyperkit.HyperKit{HyperKit:"/usr/local/bin/hyperkit", Argv0:"", StateDir:"/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000", VPNKitSock:"", VPNKitUUID:"", VPNKitPreferredIPv4:"", UUID:"8638cdce-2f94-11ee-9783-149d997fca88", Disks:[]hyperkit.Disk{(*hyperkit.RawDisk)(0xc0003ebb60)}, ISOImages:[]string{"/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/boot2docker.iso"}, VSock:false, VSockDir:"", VSockPorts:[]int(nil), VSockGuestCID:3, VMNet:true, Sockets9P:[]hyperkit.Socket9P(nil), Kernel:"/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/bzimage", Initrd:"/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/initrd", Bootrom:"", CPUs:2, Memory:2200, Console:1, Serials:[]hyperkit.Serial(nil), Pid:0, Arguments:[]string(nil), CmdLine:"", process:(*os.Proc
ess)(nil)}
I0731 04:23:41.551137 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 DEBUG: hyperkit: Arguments: []string{"-A", "-u", "-F", "/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/hyperkit.pid", "-c", "2", "-m", "2200M", "-s", "0:0,hostbridge", "-s", "31,lpc", "-s", "1:0,virtio-net", "-U", "8638cdce-2f94-11ee-9783-149d997fca88", "-s", "2:0,virtio-blk,/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/no-preload-540000.rawdisk", "-s", "3,ahci-cd,/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/boot2docker.iso", "-s", "4,virtio-rnd", "-l", "com1,autopty=/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/tty,log=/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/console-ring", "-f", "kexec,/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/bzimage,/Users/jenkins/minikube-integration/16
969-982/.minikube/machines/no-preload-540000/initrd,earlyprintk=serial loglevel=3 console=ttyS0 console=tty0 noembed nomodeset norestore waitusb=10 systemd.legacy_systemd_cgroup_controller=yes random.trust_cpu=on hw_rng_model=virtio base host=no-preload-540000"}
I0731 04:23:41.551176 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 DEBUG: hyperkit: CmdLine: "/usr/local/bin/hyperkit -A -u -F /Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/hyperkit.pid -c 2 -m 2200M -s 0:0,hostbridge -s 31,lpc -s 1:0,virtio-net -U 8638cdce-2f94-11ee-9783-149d997fca88 -s 2:0,virtio-blk,/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/no-preload-540000.rawdisk -s 3,ahci-cd,/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/boot2docker.iso -s 4,virtio-rnd -l com1,autopty=/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/tty,log=/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/console-ring -f kexec,/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/bzimage,/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/initrd,earlyprint
k=serial loglevel=3 console=ttyS0 console=tty0 noembed nomodeset norestore waitusb=10 systemd.legacy_systemd_cgroup_controller=yes random.trust_cpu=on hw_rng_model=virtio base host=no-preload-540000"
I0731 04:23:41.551196 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 DEBUG: hyperkit: Redirecting stdout/stderr to logger
I0731 04:23:41.552274 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 DEBUG: hyperkit: Pid is 8098
I0731 04:23:41.552660 8087 main.go:141] libmachine: (no-preload-540000) DBG | Attempt 0
I0731 04:23:41.552680 8087 main.go:141] libmachine: (no-preload-540000) DBG | exe=/Users/jenkins/workspace/out/docker-machine-driver-hyperkit uid=0
I0731 04:23:41.552783 8087 main.go:141] libmachine: (no-preload-540000) DBG | hyperkit pid from json: 8098
I0731 04:23:41.554783 8087 main.go:141] libmachine: (no-preload-540000) DBG | Searching for d6:ba:23:4e:ec:2 in /var/db/dhcpd_leases ...
I0731 04:23:41.554886 8087 main.go:141] libmachine: (no-preload-540000) DBG | Found 40 entries in /var/db/dhcpd_leases!
I0731 04:23:41.554914 8087 main.go:141] libmachine: (no-preload-540000) DBG | dhcp entry: {Name:minikube IPAddress:192.168.64.41 HWAddress:d6:ba:23:4e:ec:2 ID:1,d6:ba:23:4e:ec:2 Lease:0x64c8eaf9}
I0731 04:23:41.554944 8087 main.go:141] libmachine: (no-preload-540000) DBG | Found match: d6:ba:23:4e:ec:2
I0731 04:23:41.554964 8087 main.go:141] libmachine: (no-preload-540000) DBG | IP: 192.168.64.41
I0731 04:23:41.554991 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetConfigRaw
I0731 04:23:41.555707 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetIP
I0731 04:23:41.555887 8087 profile.go:148] Saving config to /Users/jenkins/minikube-integration/16969-982/.minikube/profiles/no-preload-540000/config.json ...
I0731 04:23:41.556200 8087 machine.go:88] provisioning docker machine ...
I0731 04:23:41.556210 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
I0731 04:23:41.556343 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetMachineName
I0731 04:23:41.556445 8087 buildroot.go:166] provisioning hostname "no-preload-540000"
I0731 04:23:41.556456 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetMachineName
I0731 04:23:41.556571 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:41.556661 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHPort
I0731 04:23:41.556758 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:41.556864 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:41.556961 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHUsername
I0731 04:23:41.557092 8087 main.go:141] libmachine: Using SSH client type: native
I0731 04:23:41.557438 8087 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140d220] 0x14102c0 <nil> [] 0s} 192.168.64.41 22 <nil> <nil>}
I0731 04:23:41.557447 8087 main.go:141] libmachine: About to run SSH command:
sudo hostname no-preload-540000 && echo "no-preload-540000" | sudo tee /etc/hostname
I0731 04:23:41.559095 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 INFO : hyperkit: stderr: Using fd 5 for I/O notifications
I0731 04:23:41.567060 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 INFO : hyperkit: stderr: /Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/boot2docker.iso: fcntl(F_PUNCHHOLE) Operation not permitted: block device will not support TRIM/DISCARD
I0731 04:23:41.567842 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 2 bit: 22 unspecified don't care: bit is 0
I0731 04:23:41.567859 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 4 bit: 12 unspecified don't care: bit is 0
I0731 04:23:41.567869 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 4 bit: 20 unspecified don't care: bit is 0
I0731 04:23:41.567878 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 3 bit: 13 unspecified don't care: bit is 0
I0731 04:23:41.933170 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 INFO : hyperkit: stderr: rdmsr to register 0x3a on vcpu 0
I0731 04:23:41.933186 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:41 INFO : hyperkit: stderr: rdmsr to register 0x140 on vcpu 0
I0731 04:23:42.037188 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:42 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 2 bit: 22 unspecified don't care: bit is 0
I0731 04:23:42.037206 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:42 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 4 bit: 12 unspecified don't care: bit is 0
I0731 04:23:42.037217 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:42 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 4 bit: 20 unspecified don't care: bit is 0
I0731 04:23:42.037245 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:42 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 3 bit: 13 unspecified don't care: bit is 0
I0731 04:23:42.038106 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:42 INFO : hyperkit: stderr: rdmsr to register 0x3a on vcpu 1
I0731 04:23:42.038120 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:42 INFO : hyperkit: stderr: rdmsr to register 0x140 on vcpu 1
I0731 04:23:46.865090 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:46 INFO : hyperkit: stderr: rdmsr to register 0x64d on vcpu 1
I0731 04:23:46.865123 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:46 INFO : hyperkit: stderr: rdmsr to register 0x64e on vcpu 1
I0731 04:23:46.865141 8087 main.go:141] libmachine: (no-preload-540000) DBG | 2023/07/31 04:23:46 INFO : hyperkit: stderr: rdmsr to register 0x34 on vcpu 1
I0731 04:23:54.738055 8087 main.go:141] libmachine: SSH cmd err, output: <nil>: no-preload-540000
I0731 04:23:54.738079 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:54.738233 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHPort
I0731 04:23:54.738308 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:54.738387 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:54.738465 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHUsername
I0731 04:23:54.738603 8087 main.go:141] libmachine: Using SSH client type: native
I0731 04:23:54.738914 8087 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140d220] 0x14102c0 <nil> [] 0s} 192.168.64.41 22 <nil> <nil>}
I0731 04:23:54.738926 8087 main.go:141] libmachine: About to run SSH command:
if ! grep -xq '.*\sno-preload-540000' /etc/hosts; then
if grep -xq '127.0.1.1\s.*' /etc/hosts; then
sudo sed -i 's/^127.0.1.1\s.*/127.0.1.1 no-preload-540000/g' /etc/hosts;
else
echo '127.0.1.1 no-preload-540000' | sudo tee -a /etc/hosts;
fi
fi
I0731 04:23:54.804474 8087 main.go:141] libmachine: SSH cmd err, output: <nil>:
I0731 04:23:54.804492 8087 buildroot.go:172] set auth options {CertDir:/Users/jenkins/minikube-integration/16969-982/.minikube CaCertPath:/Users/jenkins/minikube-integration/16969-982/.minikube/certs/ca.pem CaPrivateKeyPath:/Users/jenkins/minikube-integration/16969-982/.minikube/certs/ca-key.pem CaCertRemotePath:/etc/docker/ca.pem ServerCertPath:/Users/jenkins/minikube-integration/16969-982/.minikube/machines/server.pem ServerKeyPath:/Users/jenkins/minikube-integration/16969-982/.minikube/machines/server-key.pem ClientKeyPath:/Users/jenkins/minikube-integration/16969-982/.minikube/certs/key.pem ServerCertRemotePath:/etc/docker/server.pem ServerKeyRemotePath:/etc/docker/server-key.pem ClientCertPath:/Users/jenkins/minikube-integration/16969-982/.minikube/certs/cert.pem ServerCertSANs:[] StorePath:/Users/jenkins/minikube-integration/16969-982/.minikube}
I0731 04:23:54.804511 8087 buildroot.go:174] setting up certificates
I0731 04:23:54.804522 8087 provision.go:83] configureAuth start
I0731 04:23:54.804528 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetMachineName
I0731 04:23:54.804667 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetIP
I0731 04:23:54.804766 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:54.804859 8087 provision.go:138] copyHostCerts
I0731 04:23:54.804929 8087 exec_runner.go:144] found /Users/jenkins/minikube-integration/16969-982/.minikube/ca.pem, removing ...
I0731 04:23:54.804938 8087 exec_runner.go:203] rm: /Users/jenkins/minikube-integration/16969-982/.minikube/ca.pem
I0731 04:23:54.805058 8087 exec_runner.go:151] cp: /Users/jenkins/minikube-integration/16969-982/.minikube/certs/ca.pem --> /Users/jenkins/minikube-integration/16969-982/.minikube/ca.pem (1082 bytes)
I0731 04:23:54.805290 8087 exec_runner.go:144] found /Users/jenkins/minikube-integration/16969-982/.minikube/cert.pem, removing ...
I0731 04:23:54.805296 8087 exec_runner.go:203] rm: /Users/jenkins/minikube-integration/16969-982/.minikube/cert.pem
I0731 04:23:54.805361 8087 exec_runner.go:151] cp: /Users/jenkins/minikube-integration/16969-982/.minikube/certs/cert.pem --> /Users/jenkins/minikube-integration/16969-982/.minikube/cert.pem (1123 bytes)
I0731 04:23:54.805527 8087 exec_runner.go:144] found /Users/jenkins/minikube-integration/16969-982/.minikube/key.pem, removing ...
I0731 04:23:54.805533 8087 exec_runner.go:203] rm: /Users/jenkins/minikube-integration/16969-982/.minikube/key.pem
I0731 04:23:54.805598 8087 exec_runner.go:151] cp: /Users/jenkins/minikube-integration/16969-982/.minikube/certs/key.pem --> /Users/jenkins/minikube-integration/16969-982/.minikube/key.pem (1679 bytes)
I0731 04:23:54.805736 8087 provision.go:112] generating server cert: /Users/jenkins/minikube-integration/16969-982/.minikube/machines/server.pem ca-key=/Users/jenkins/minikube-integration/16969-982/.minikube/certs/ca.pem private-key=/Users/jenkins/minikube-integration/16969-982/.minikube/certs/ca-key.pem org=jenkins.no-preload-540000 san=[192.168.64.41 192.168.64.41 localhost 127.0.0.1 minikube no-preload-540000]
I0731 04:23:54.913516 8087 provision.go:172] copyRemoteCerts
I0731 04:23:54.913577 8087 ssh_runner.go:195] Run: sudo mkdir -p /etc/docker /etc/docker /etc/docker
I0731 04:23:54.913593 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:54.913733 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHPort
I0731 04:23:54.913824 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:54.913905 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHUsername
I0731 04:23:54.913993 8087 sshutil.go:53] new ssh client: &{IP:192.168.64.41 Port:22 SSHKeyPath:/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/id_rsa Username:docker}
I0731 04:23:54.949576 8087 ssh_runner.go:362] scp /Users/jenkins/minikube-integration/16969-982/.minikube/certs/ca.pem --> /etc/docker/ca.pem (1082 bytes)
I0731 04:23:54.965378 8087 ssh_runner.go:362] scp /Users/jenkins/minikube-integration/16969-982/.minikube/machines/server.pem --> /etc/docker/server.pem (1229 bytes)
I0731 04:23:54.981352 8087 ssh_runner.go:362] scp /Users/jenkins/minikube-integration/16969-982/.minikube/machines/server-key.pem --> /etc/docker/server-key.pem (1679 bytes)
I0731 04:23:54.997104 8087 provision.go:86] duration metric: configureAuth took 192.57495ms
I0731 04:23:54.997115 8087 buildroot.go:189] setting minikube options for container-runtime
I0731 04:23:54.997251 8087 config.go:182] Loaded profile config "no-preload-540000": Driver=hyperkit, ContainerRuntime=docker, KubernetesVersion=v1.27.3
I0731 04:23:54.997264 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
I0731 04:23:54.997392 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:54.997481 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHPort
I0731 04:23:54.997570 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:54.997696 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:54.997774 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHUsername
I0731 04:23:54.997897 8087 main.go:141] libmachine: Using SSH client type: native
I0731 04:23:54.998187 8087 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140d220] 0x14102c0 <nil> [] 0s} 192.168.64.41 22 <nil> <nil>}
I0731 04:23:54.998194 8087 main.go:141] libmachine: About to run SSH command:
df --output=fstype / | tail -n 1
I0731 04:23:55.058043 8087 main.go:141] libmachine: SSH cmd err, output: <nil>: tmpfs
I0731 04:23:55.058054 8087 buildroot.go:70] root file system type: tmpfs
I0731 04:23:55.058125 8087 provision.go:309] Updating docker unit: /lib/systemd/system/docker.service ...
I0731 04:23:55.058145 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:55.058284 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHPort
I0731 04:23:55.058364 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:55.058465 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:55.058551 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHUsername
I0731 04:23:55.058681 8087 main.go:141] libmachine: Using SSH client type: native
I0731 04:23:55.058981 8087 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140d220] 0x14102c0 <nil> [] 0s} 192.168.64.41 22 <nil> <nil>}
I0731 04:23:55.059026 8087 main.go:141] libmachine: About to run SSH command:
sudo mkdir -p /lib/systemd/system && printf %s "[Unit]
Description=Docker Application Container Engine
Documentation=https://docs.docker.com
After=network.target minikube-automount.service docker.socket
Requires= minikube-automount.service docker.socket
StartLimitBurst=3
StartLimitIntervalSec=60
[Service]
Type=notify
Restart=on-failure
# This file is a systemd drop-in unit that inherits from the base dockerd configuration.
# The base configuration already specifies an 'ExecStart=...' command. The first directive
# here is to clear out that command inherited from the base configuration. Without this,
# the command from the base configuration and the command specified here are treated as
# a sequence of commands, which is not the desired behavior, nor is it valid -- systemd
# will catch this invalid input and refuse to start the service with an error like:
# Service has more than one ExecStart= setting, which is only allowed for Type=oneshot services.
# NOTE: default-ulimit=nofile is set to an arbitrary number for consistency with other
# container runtimes. If left unlimited, it may result in OOM issues with MySQL.
ExecStart=
ExecStart=/usr/bin/dockerd -H tcp://0.0.0.0:2376 -H unix:///var/run/docker.sock --default-ulimit=nofile=1048576:1048576 --tlsverify --tlscacert /etc/docker/ca.pem --tlscert /etc/docker/server.pem --tlskey /etc/docker/server-key.pem --label provider=hyperkit --insecure-registry 10.96.0.0/12
ExecReload=/bin/kill -s HUP \$MAINPID
# Having non-zero Limit*s causes performance problems due to accounting overhead
# in the kernel. We recommend using cgroups to do container-local accounting.
LimitNOFILE=infinity
LimitNPROC=infinity
LimitCORE=infinity
# Uncomment TasksMax if your systemd version supports it.
# Only systemd 226 and above support this version.
TasksMax=infinity
TimeoutStartSec=0
# set delegate yes so that systemd does not reset the cgroups of docker containers
Delegate=yes
# kill only the docker process, not all processes in the cgroup
KillMode=process
[Install]
WantedBy=multi-user.target
" | sudo tee /lib/systemd/system/docker.service.new
I0731 04:23:55.127762 8087 main.go:141] libmachine: SSH cmd err, output: <nil>: [Unit]
Description=Docker Application Container Engine
Documentation=https://docs.docker.com
After=network.target minikube-automount.service docker.socket
Requires= minikube-automount.service docker.socket
StartLimitBurst=3
StartLimitIntervalSec=60
[Service]
Type=notify
Restart=on-failure
# This file is a systemd drop-in unit that inherits from the base dockerd configuration.
# The base configuration already specifies an 'ExecStart=...' command. The first directive
# here is to clear out that command inherited from the base configuration. Without this,
# the command from the base configuration and the command specified here are treated as
# a sequence of commands, which is not the desired behavior, nor is it valid -- systemd
# will catch this invalid input and refuse to start the service with an error like:
# Service has more than one ExecStart= setting, which is only allowed for Type=oneshot services.
# NOTE: default-ulimit=nofile is set to an arbitrary number for consistency with other
# container runtimes. If left unlimited, it may result in OOM issues with MySQL.
ExecStart=
ExecStart=/usr/bin/dockerd -H tcp://0.0.0.0:2376 -H unix:///var/run/docker.sock --default-ulimit=nofile=1048576:1048576 --tlsverify --tlscacert /etc/docker/ca.pem --tlscert /etc/docker/server.pem --tlskey /etc/docker/server-key.pem --label provider=hyperkit --insecure-registry 10.96.0.0/12
ExecReload=/bin/kill -s HUP $MAINPID
# Having non-zero Limit*s causes performance problems due to accounting overhead
# in the kernel. We recommend using cgroups to do container-local accounting.
LimitNOFILE=infinity
LimitNPROC=infinity
LimitCORE=infinity
# Uncomment TasksMax if your systemd version supports it.
# Only systemd 226 and above support this version.
TasksMax=infinity
TimeoutStartSec=0
# set delegate yes so that systemd does not reset the cgroups of docker containers
Delegate=yes
# kill only the docker process, not all processes in the cgroup
KillMode=process
[Install]
WantedBy=multi-user.target
I0731 04:23:55.127786 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:55.127919 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHPort
I0731 04:23:55.128023 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:55.128130 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:55.128210 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHUsername
I0731 04:23:55.128343 8087 main.go:141] libmachine: Using SSH client type: native
I0731 04:23:55.128651 8087 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140d220] 0x14102c0 <nil> [] 0s} 192.168.64.41 22 <nil> <nil>}
I0731 04:23:55.128664 8087 main.go:141] libmachine: About to run SSH command:
sudo diff -u /lib/systemd/system/docker.service /lib/systemd/system/docker.service.new || { sudo mv /lib/systemd/system/docker.service.new /lib/systemd/system/docker.service; sudo systemctl -f daemon-reload && sudo systemctl -f enable docker && sudo systemctl -f restart docker; }
I0731 04:23:55.682712 8087 main.go:141] libmachine: SSH cmd err, output: <nil>: diff: can't stat '/lib/systemd/system/docker.service': No such file or directory
Created symlink /etc/systemd/system/multi-user.target.wants/docker.service → /usr/lib/systemd/system/docker.service.
I0731 04:23:55.682726 8087 machine.go:91] provisioned docker machine in 14.126798742s
I0731 04:23:55.682736 8087 start.go:300] post-start starting for "no-preload-540000" (driver="hyperkit")
I0731 04:23:55.682758 8087 start.go:329] creating required directories: [/etc/kubernetes/addons /etc/kubernetes/manifests /var/tmp/minikube /var/lib/minikube /var/lib/minikube/certs /var/lib/minikube/images /var/lib/minikube/binaries /tmp/gvisor /usr/share/ca-certificates /etc/ssl/certs]
I0731 04:23:55.682774 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
I0731 04:23:55.682956 8087 ssh_runner.go:195] Run: sudo mkdir -p /etc/kubernetes/addons /etc/kubernetes/manifests /var/tmp/minikube /var/lib/minikube /var/lib/minikube/certs /var/lib/minikube/images /var/lib/minikube/binaries /tmp/gvisor /usr/share/ca-certificates /etc/ssl/certs
I0731 04:23:55.682971 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:55.683056 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHPort
I0731 04:23:55.683137 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:55.683213 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHUsername
I0731 04:23:55.683302 8087 sshutil.go:53] new ssh client: &{IP:192.168.64.41 Port:22 SSHKeyPath:/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/id_rsa Username:docker}
I0731 04:23:55.718801 8087 ssh_runner.go:195] Run: cat /etc/os-release
I0731 04:23:55.721454 8087 info.go:137] Remote host: Buildroot 2021.02.12
I0731 04:23:55.721466 8087 filesync.go:126] Scanning /Users/jenkins/minikube-integration/16969-982/.minikube/addons for local assets ...
I0731 04:23:55.721564 8087 filesync.go:126] Scanning /Users/jenkins/minikube-integration/16969-982/.minikube/files for local assets ...
I0731 04:23:55.721734 8087 filesync.go:149] local asset: /Users/jenkins/minikube-integration/16969-982/.minikube/files/etc/ssl/certs/14542.pem -> 14542.pem in /etc/ssl/certs
I0731 04:23:55.721892 8087 ssh_runner.go:195] Run: sudo mkdir -p /etc/ssl/certs
I0731 04:23:55.727945 8087 ssh_runner.go:362] scp /Users/jenkins/minikube-integration/16969-982/.minikube/files/etc/ssl/certs/14542.pem --> /etc/ssl/certs/14542.pem (1708 bytes)
I0731 04:23:55.743673 8087 start.go:303] post-start completed in 60.929173ms
I0731 04:23:55.743691 8087 fix.go:56] fixHost completed within 14.294432847s
I0731 04:23:55.743708 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:55.743843 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHPort
I0731 04:23:55.743921 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:55.744011 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:55.744082 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHUsername
I0731 04:23:55.744213 8087 main.go:141] libmachine: Using SSH client type: native
I0731 04:23:55.744511 8087 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140d220] 0x14102c0 <nil> [] 0s} 192.168.64.41 22 <nil> <nil>}
I0731 04:23:55.744518 8087 main.go:141] libmachine: About to run SSH command:
date +%s.%N
I0731 04:23:55.804997 8087 main.go:141] libmachine: SSH cmd err, output: <nil>: 1690802635.963011829
I0731 04:23:55.805010 8087 fix.go:206] guest clock: 1690802635.963011829
I0731 04:23:55.805015 8087 fix.go:219] Guest: 2023-07-31 04:23:55.963011829 -0700 PDT Remote: 2023-07-31 04:23:55.743696 -0700 PDT m=+14.695229257 (delta=219.315829ms)
I0731 04:23:55.805042 8087 fix.go:190] guest clock delta is within tolerance: 219.315829ms
I0731 04:23:55.805046 8087 start.go:83] releasing machines lock for "no-preload-540000", held for 14.355829208s
I0731 04:23:55.805065 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
I0731 04:23:55.805191 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetIP
I0731 04:23:55.805279 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
I0731 04:23:55.805553 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
I0731 04:23:55.805647 8087 main.go:141] libmachine: (no-preload-540000) Calling .DriverName
I0731 04:23:55.805730 8087 ssh_runner.go:195] Run: curl -sS -m 2 https://registry.k8s.io/
I0731 04:23:55.805763 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:55.805772 8087 ssh_runner.go:195] Run: cat /version.json
I0731 04:23:55.805785 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHHostname
I0731 04:23:55.805871 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHPort
I0731 04:23:55.805895 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHPort
I0731 04:23:55.805951 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:55.805980 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHKeyPath
I0731 04:23:55.806036 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHUsername
I0731 04:23:55.806065 8087 main.go:141] libmachine: (no-preload-540000) Calling .GetSSHUsername
I0731 04:23:55.806133 8087 sshutil.go:53] new ssh client: &{IP:192.168.64.41 Port:22 SSHKeyPath:/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/id_rsa Username:docker}
I0731 04:23:55.806155 8087 sshutil.go:53] new ssh client: &{IP:192.168.64.41 Port:22 SSHKeyPath:/Users/jenkins/minikube-integration/16969-982/.minikube/machines/no-preload-540000/id_rsa Username:docker}
I0731 04:23:55.880112 8087 ssh_runner.go:195] Run: systemctl --version
I0731 04:23:55.884245 8087 ssh_runner.go:195] Run: sh -c "stat /etc/cni/net.d/*loopback.conf*"
W0731 04:23:55.887674 8087 cni.go:209] loopback cni configuration skipped: "/etc/cni/net.d/*loopback.conf*" not found
I0731 04:23:55.887724 8087 ssh_runner.go:195] Run: sudo find /etc/cni/net.d -maxdepth 1 -type f ( ( -name *bridge* -or -name *podman* ) -and -not -name *.mk_disabled ) -printf "%p, " -exec sh -c "sudo mv {} {}.mk_disabled" ;
I0731 04:23:55.897896 8087 cni.go:262] disabled [/etc/cni/net.d/87-podman-bridge.conflist] bridge cni config(s)
I0731 04:23:55.897911 8087 start.go:466] detecting cgroup driver to use...
I0731 04:23:55.898011 8087 ssh_runner.go:195] Run: /bin/bash -c "sudo mkdir -p /etc && printf %s "runtime-endpoint: unix:///run/containerd/containerd.sock
" | sudo tee /etc/crictl.yaml"
I0731 04:23:55.911223 8087 ssh_runner.go:195] Run: sh -c "sudo sed -i -r 's|^( *)sandbox_image = .*$|\1sandbox_image = "registry.k8s.io/pause:3.9"|' /etc/containerd/config.toml"
I0731 04:23:55.917558 8087 ssh_runner.go:195] Run: sh -c "sudo sed -i -r 's|^( *)restrict_oom_score_adj = .*$|\1restrict_oom_score_adj = false|' /etc/containerd/config.toml"
I0731 04:23:55.923932 8087 containerd.go:145] configuring containerd to use "cgroupfs" as cgroup driver...
I0731 04:23:55.923980 8087 ssh_runner.go:195] Run: sh -c "sudo sed -i -r 's|^( *)SystemdCgroup = .*$|\1SystemdCgroup = false|g' /etc/containerd/config.toml"
I0731 04:23:55.930452 8087 ssh_runner.go:195] Run: sh -c "sudo sed -i 's|"io.containerd.runtime.v1.linux"|"io.containerd.runc.v2"|g' /etc/containerd/config.toml"
I0731 04:23:55.936951 8087 ssh_runner.go:195] Run: sh -c "sudo sed -i '/systemd_cgroup/d' /etc/containerd/config.toml"
I0731 04:23:55.943447 8087 ssh_runner.go:195] Run: sh -c "sudo sed -i 's|"io.containerd.runc.v1"|"io.containerd.runc.v2"|g' /etc/containerd/config.toml"
I0731 04:23:55.949871 8087 ssh_runner.go:195] Run: sh -c "sudo rm -rf /etc/cni/net.mk"
I0731 04:23:55.956526 8087 ssh_runner.go:195] Run: sh -c "sudo sed -i -r 's|^( *)conf_dir = .*$|\1conf_dir = "/etc/cni/net.d"|g' /etc/containerd/config.toml"
I0731 04:23:55.963040 8087 ssh_runner.go:195] Run: sudo sysctl net.bridge.bridge-nf-call-iptables
I0731 04:23:55.968964 8087 ssh_runner.go:195] Run: sudo sh -c "echo 1 > /proc/sys/net/ipv4/ip_forward"
I0731 04:23:55.974811 8087 ssh_runner.go:195] Run: sudo systemctl daemon-reload
I0731 04:23:56.062183 8087 ssh_runner.go:195] Run: sudo systemctl restart containerd
I0731 04:23:56.073578 8087 start.go:466] detecting cgroup driver to use...
I0731 04:23:56.073649 8087 ssh_runner.go:195] Run: sudo systemctl cat docker.service
I0731 04:23:56.082708 8087 ssh_runner.go:195] Run: sudo systemctl is-active --quiet service containerd
I0731 04:23:56.114490 8087 ssh_runner.go:195] Run: sudo systemctl stop -f containerd
I0731 04:23:56.129607 8087 ssh_runner.go:195] Run: sudo systemctl is-active --quiet service containerd
I0731 04:23:56.137861 8087 ssh_runner.go:195] Run: sudo systemctl is-active --quiet service crio
I0731 04:23:56.146206 8087 ssh_runner.go:195] Run: sudo systemctl stop -f crio
I0731 04:23:56.170636 8087 ssh_runner.go:195] Run: sudo systemctl is-active --quiet service crio
I0731 04:23:56.179191 8087 ssh_runner.go:195] Run: /bin/bash -c "sudo mkdir -p /etc && printf %s "runtime-endpoint: unix:///var/run/cri-dockerd.sock
" | sudo tee /etc/crictl.yaml"
I0731 04:23:56.192288 8087 ssh_runner.go:195] Run: which cri-dockerd
I0731 04:23:56.194640 8087 ssh_runner.go:195] Run: sudo mkdir -p /etc/systemd/system/cri-docker.service.d
I0731 04:23:56.200846 8087 ssh_runner.go:362] scp memory --> /etc/systemd/system/cri-docker.service.d/10-cni.conf (189 bytes)
I0731 04:23:56.211931 8087 ssh_runner.go:195] Run: sudo systemctl unmask docker.service
I0731 04:23:56.295325 8087 ssh_runner.go:195] Run: sudo systemctl enable docker.socket
I0731 04:23:56.381988 8087 docker.go:535] configuring docker to use "cgroupfs" as cgroup driver...
I0731 04:23:56.382004 8087 ssh_runner.go:362] scp memory --> /etc/docker/daemon.json (144 bytes)
I0731 04:23:56.393613 8087 ssh_runner.go:195] Run: sudo systemctl daemon-reload
I0731 04:23:56.477218 8087 ssh_runner.go:195] Run: sudo systemctl restart docker
I0731 04:24:57.519937 8087 ssh_runner.go:235] Completed: sudo systemctl restart docker: (1m1.043910876s)
I0731 04:24:57.541634 8087 out.go:177]
W0731 04:24:57.562506 8087 out.go:239] X Exiting due to RUNTIME_ENABLE: Failed to enable container runtime: sudo systemctl restart docker: Process exited with status 1
stdout:
stderr:
Job for docker.service failed because the control process exited with error code.
See "systemctl status docker.service" and "journalctl -xe" for details.
X Exiting due to RUNTIME_ENABLE: Failed to enable container runtime: sudo systemctl restart docker: Process exited with status 1
stdout:
stderr:
Job for docker.service failed because the control process exited with error code.
See "systemctl status docker.service" and "journalctl -xe" for details.
W0731 04:24:57.562544 8087 out.go:239] *
*
W0731 04:24:57.563493 8087 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. │
│ │
╰─────────────────────────────────────────────────────────────────────────────────────────────╯
╭─────────────────────────────────────────────────────────────────────────────────────────────╮
│ │
│ * 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. │
│ │
╰─────────────────────────────────────────────────────────────────────────────────────────────╯
I0731 04:24:57.626344 8087 out.go:177]
** /stderr **
start_stop_delete_test.go:259: failed to start minikube post-stop. args "out/minikube-darwin-amd64 start -p no-preload-540000 --memory=2200 --alsologtostderr --wait=true --preload=false --driver=hyperkit --kubernetes-version=v1.27.3": exit status 90
helpers_test.go:222: -----------------------post-mortem--------------------------------
helpers_test.go:239: (dbg) Run: out/minikube-darwin-amd64 status --format={{.Host}} -p no-preload-540000 -n no-preload-540000
helpers_test.go:239: (dbg) Non-zero exit: out/minikube-darwin-amd64 status --format={{.Host}} -p no-preload-540000 -n no-preload-540000: exit status 6 (122.158911ms)
-- stdout --
Running
WARNING: Your kubectl is pointing to stale minikube-vm.
To fix the kubectl context, run `minikube update-context`
-- /stdout --
** stderr **
E0731 04:24:57.793165 8247 status.go:415] kubeconfig endpoint: extract IP: "no-preload-540000" does not appear in /Users/jenkins/minikube-integration/16969-982/kubeconfig
** /stderr **
helpers_test.go:239: status error: exit status 6 (may be ok)
helpers_test.go:241: "no-preload-540000" host is not running, skipping log retrieval (state="Running\nWARNING: Your kubectl is pointing to stale minikube-vm.\nTo fix the kubectl context, run `minikube update-context`")
--- FAIL: TestStartStop/group/no-preload/serial/SecondStart (76.76s)