=== RUN TestStartStop/group/newest-cni/serial/SecondStart
start_stop_delete_test.go:256: (dbg) Run: out/minikube-darwin-amd64 start -p newest-cni-829000 --memory=2200 --alsologtostderr --wait=apiserver,system_pods,default_sa --feature-gates ServerSideApply=true --network-plugin=cni --extra-config=kubeadm.pod-network-cidr=10.42.0.0/16 --driver=hyperkit --kubernetes-version=v1.26.1
E0223 17:44:15.141760 2206 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/15909-975/.minikube/profiles/kindnet-951000/client.crt: no such file or directory
E0223 17:44:26.770966 2206 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/15909-975/.minikube/profiles/calico-951000/client.crt: no such file or directory
E0223 17:44:28.868085 2206 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/15909-975/.minikube/profiles/custom-flannel-951000/client.crt: no such file or directory
E0223 17:44:31.886327 2206 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/15909-975/.minikube/profiles/functional-883000/client.crt: no such file or directory
E0223 17:44:48.829858 2206 cert_rotation.go:168] key failed with : open /Users/jenkins/minikube-integration/15909-975/.minikube/profiles/functional-883000/client.crt: no such file or directory
start_stop_delete_test.go:256: (dbg) Non-zero exit: out/minikube-darwin-amd64 start -p newest-cni-829000 --memory=2200 --alsologtostderr --wait=apiserver,system_pods,default_sa --feature-gates ServerSideApply=true --network-plugin=cni --extra-config=kubeadm.pod-network-cidr=10.42.0.0/16 --driver=hyperkit --kubernetes-version=v1.26.1: exit status 90 (1m16.330230646s)
-- stdout --
* [newest-cni-829000] minikube v1.29.0 on Darwin 13.2
- MINIKUBE_LOCATION=15909
- KUBECONFIG=/Users/jenkins/minikube-integration/15909-975/kubeconfig
- MINIKUBE_BIN=out/minikube-darwin-amd64
- MINIKUBE_SUPPRESS_DOCKER_PERFORMANCE=true
- MINIKUBE_HOME=/Users/jenkins/minikube-integration/15909-975/.minikube
- MINIKUBE_FORCE_SYSTEMD=
* Using the hyperkit driver based on existing profile
* Starting control plane node newest-cni-829000 in cluster newest-cni-829000
* Restarting existing hyperkit VM for "newest-cni-829000" ...
-- /stdout --
** stderr **
I0223 17:44:13.333360 12805 out.go:296] Setting OutFile to fd 1 ...
I0223 17:44:13.333520 12805 out.go:343] TERM=,COLORTERM=, which probably does not support color
I0223 17:44:13.333526 12805 out.go:309] Setting ErrFile to fd 2...
I0223 17:44:13.333530 12805 out.go:343] TERM=,COLORTERM=, which probably does not support color
I0223 17:44:13.333633 12805 root.go:336] Updating PATH: /Users/jenkins/minikube-integration/15909-975/.minikube/bin
I0223 17:44:13.335055 12805 out.go:303] Setting JSON to false
I0223 17:44:13.354599 12805 start.go:125] hostinfo: {"hostname":"MacOS-Agent-2.local","uptime":4428,"bootTime":1677198625,"procs":399,"os":"darwin","platform":"darwin","platformFamily":"Standalone Workstation","platformVersion":"13.2","kernelVersion":"22.3.0","kernelArch":"x86_64","virtualizationSystem":"","virtualizationRole":"","hostId":"2965c349-98a5-5970-aaa9-9eedd3ae5959"}
W0223 17:44:13.354672 12805 start.go:133] gopshost.Virtualization returned error: not implemented yet
I0223 17:44:13.375761 12805 out.go:177] * [newest-cni-829000] minikube v1.29.0 on Darwin 13.2
I0223 17:44:13.417431 12805 notify.go:220] Checking for updates...
I0223 17:44:13.438396 12805 out.go:177] - MINIKUBE_LOCATION=15909
I0223 17:44:13.459824 12805 out.go:177] - KUBECONFIG=/Users/jenkins/minikube-integration/15909-975/kubeconfig
I0223 17:44:13.480566 12805 out.go:177] - MINIKUBE_BIN=out/minikube-darwin-amd64
I0223 17:44:13.502039 12805 out.go:177] - MINIKUBE_SUPPRESS_DOCKER_PERFORMANCE=true
I0223 17:44:13.523952 12805 out.go:177] - MINIKUBE_HOME=/Users/jenkins/minikube-integration/15909-975/.minikube
I0223 17:44:13.544572 12805 out.go:177] - MINIKUBE_FORCE_SYSTEMD=
I0223 17:44:13.566462 12805 config.go:182] Loaded profile config "newest-cni-829000": Driver=hyperkit, ContainerRuntime=docker, KubernetesVersion=v1.26.1
I0223 17:44:13.567157 12805 main.go:141] libmachine: Found binary path at /Users/jenkins/workspace/out/docker-machine-driver-hyperkit
I0223 17:44:13.567240 12805 main.go:141] libmachine: Launching plugin server for driver hyperkit
I0223 17:44:13.574960 12805 main.go:141] libmachine: Plugin server listening at address 127.0.0.1:56678
I0223 17:44:13.575308 12805 main.go:141] libmachine: () Calling .GetVersion
I0223 17:44:13.575741 12805 main.go:141] libmachine: Using API Version 1
I0223 17:44:13.575753 12805 main.go:141] libmachine: () Calling .SetConfigRaw
I0223 17:44:13.575958 12805 main.go:141] libmachine: () Calling .GetMachineName
I0223 17:44:13.576075 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
I0223 17:44:13.576187 12805 driver.go:365] Setting default libvirt URI to qemu:///system
I0223 17:44:13.576440 12805 main.go:141] libmachine: Found binary path at /Users/jenkins/workspace/out/docker-machine-driver-hyperkit
I0223 17:44:13.576462 12805 main.go:141] libmachine: Launching plugin server for driver hyperkit
I0223 17:44:13.583060 12805 main.go:141] libmachine: Plugin server listening at address 127.0.0.1:56680
I0223 17:44:13.583399 12805 main.go:141] libmachine: () Calling .GetVersion
I0223 17:44:13.583779 12805 main.go:141] libmachine: Using API Version 1
I0223 17:44:13.583794 12805 main.go:141] libmachine: () Calling .SetConfigRaw
I0223 17:44:13.584015 12805 main.go:141] libmachine: () Calling .GetMachineName
I0223 17:44:13.584110 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
I0223 17:44:13.611612 12805 out.go:177] * Using the hyperkit driver based on existing profile
I0223 17:44:13.653586 12805 start.go:296] selected driver: hyperkit
I0223 17:44:13.653613 12805 start.go:857] validating driver "hyperkit" against &{Name:newest-cni-829000 KeepContext:false EmbedCerts:false MinikubeISO:https://storage.googleapis.com/minikube-builds/iso/15849/minikube-v1.29.0-1676568791-15849-amd64.iso KicBaseImage:gcr.io/k8s-minikube/kicbase-builds:v0.0.37-1676506612-15768@sha256:cc1cb283879fedae93096946a6953a50075ed680d467a47cbf669e0ed7d3aebc 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 Kubernet
esConfig:{KubernetesVersion:v1.26.1 ClusterName:newest-cni-829000 Namespace:default APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin:cni FeatureGates:ServerSideApply=true ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: CustomIngressCert: RegistryAliases: ExtraOptions:[{Component:kubeadm Key:pod-network-cidr Value:10.42.0.0/16}] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI: NodeIP: NodePort:8443 NodeName:} Nodes:[{Name: IP:192.168.64.44 Port:8443 KubernetesVersion:v1.26.1 ContainerRuntime:docker ControlPlane:true Worker:true}] Addons:map[dashboard:true default-storageclass:true metrics-server:true storage-provisioner:true] CustomAddonImages:map[MetricsScraper:k8s.gcr.io/echoserver:1.4 MetricsServer:k8s.gcr.io/echoserver:1.4] CustomAddonRegistries:map[MetricsServer:fake.domain] VerifyComponents:map[apiserver:true apps_running:false default_sa:true extra:false kubelet:false node_ready:fa
lse system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[] ListenAddress: Network: 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: SocketVMnetClientPath: SocketVMnetPath: StaticIP:}
I0223 17:44:13.653798 12805 start.go:868] status for hyperkit: {Installed:true Healthy:true Running:true NeedsImprovement:false Error:<nil> Reason: Fix: Doc: Version:}
I0223 17:44:13.657419 12805 install.go:52] acquiring lock: {Name:mk4023283b30b374c3f04c8805d539e68824c0b8 Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0223 17:44:13.657541 12805 install.go:117] Validating docker-machine-driver-hyperkit, PATH=/Users/jenkins/minikube-integration/15909-975/.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
I0223 17:44:13.664205 12805 install.go:137] /Users/jenkins/workspace/out/docker-machine-driver-hyperkit version is 1.29.0
I0223 17:44:13.667444 12805 install.go:79] stdout: /Users/jenkins/workspace/out/docker-machine-driver-hyperkit
I0223 17:44:13.667463 12805 install.go:81] /Users/jenkins/workspace/out/docker-machine-driver-hyperkit looks good
I0223 17:44:13.667565 12805 start_flags.go:938] Waiting for components: map[apiserver:true apps_running:false default_sa:true extra:false kubelet:false node_ready:false system_pods:true]
I0223 17:44:13.667586 12805 cni.go:84] Creating CNI manager for ""
I0223 17:44:13.667606 12805 cni.go:157] "hyperkit" driver + "docker" container runtime found on kubernetes v1.24+, recommending bridge
I0223 17:44:13.667614 12805 start_flags.go:319] config:
{Name:newest-cni-829000 KeepContext:false EmbedCerts:false MinikubeISO:https://storage.googleapis.com/minikube-builds/iso/15849/minikube-v1.29.0-1676568791-15849-amd64.iso KicBaseImage:gcr.io/k8s-minikube/kicbase-builds:v0.0.37-1676506612-15768@sha256:cc1cb283879fedae93096946a6953a50075ed680d467a47cbf669e0ed7d3aebc 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.26.1 ClusterName:newest-cni-829000 Namespace:defaul
t APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin:cni FeatureGates:ServerSideApply=true ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: CustomIngressCert: RegistryAliases: ExtraOptions:[{Component:kubeadm Key:pod-network-cidr Value:10.42.0.0/16}] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI: NodeIP: NodePort:8443 NodeName:} Nodes:[{Name: IP:192.168.64.44 Port:8443 KubernetesVersion:v1.26.1 ContainerRuntime:docker ControlPlane:true Worker:true}] Addons:map[dashboard:true default-storageclass:true metrics-server:true storage-provisioner:true] CustomAddonImages:map[MetricsScraper:k8s.gcr.io/echoserver:1.4 MetricsServer:k8s.gcr.io/echoserver:1.4] CustomAddonRegistries:map[MetricsServer:fake.domain] VerifyComponents:map[apiserver:true apps_running:false default_sa:true extra:false kubelet:false node_ready:false system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[] Li
stenAddress: Network: 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: SocketVMnetClientPath: SocketVMnetPath: StaticIP:}
I0223 17:44:13.667721 12805 iso.go:125] acquiring lock: {Name:mkb579d69c68eeeaf4241c144e3709e237809e4d Clock:{} Delay:500ms Timeout:10m0s Cancel:<nil>}
I0223 17:44:13.688828 12805 out.go:177] * Starting control plane node newest-cni-829000 in cluster newest-cni-829000
I0223 17:44:13.730826 12805 preload.go:132] Checking if preload exists for k8s version v1.26.1 and runtime docker
I0223 17:44:13.730911 12805 preload.go:148] Found local preload: /Users/jenkins/minikube-integration/15909-975/.minikube/cache/preloaded-tarball/preloaded-images-k8s-v18-v1.26.1-docker-overlay2-amd64.tar.lz4
I0223 17:44:13.730943 12805 cache.go:57] Caching tarball of preloaded images
I0223 17:44:13.731133 12805 preload.go:174] Found /Users/jenkins/minikube-integration/15909-975/.minikube/cache/preloaded-tarball/preloaded-images-k8s-v18-v1.26.1-docker-overlay2-amd64.tar.lz4 in cache, skipping download
I0223 17:44:13.731151 12805 cache.go:60] Finished verifying existence of preloaded tar for v1.26.1 on docker
I0223 17:44:13.731316 12805 profile.go:148] Saving config to /Users/jenkins/minikube-integration/15909-975/.minikube/profiles/newest-cni-829000/config.json ...
I0223 17:44:13.732098 12805 cache.go:193] Successfully downloaded all kic artifacts
I0223 17:44:13.732150 12805 start.go:364] acquiring machines lock for newest-cni-829000: {Name:mk9ac83758ce2327622daf3508e9f994d699228c Clock:{} Delay:500ms Timeout:13m0s Cancel:<nil>}
I0223 17:44:13.732246 12805 start.go:368] acquired machines lock for "newest-cni-829000" in 77.646µs
I0223 17:44:13.732297 12805 start.go:96] Skipping create...Using existing machine configuration
I0223 17:44:13.732310 12805 fix.go:55] fixHost starting:
I0223 17:44:13.732754 12805 main.go:141] libmachine: Found binary path at /Users/jenkins/workspace/out/docker-machine-driver-hyperkit
I0223 17:44:13.732792 12805 main.go:141] libmachine: Launching plugin server for driver hyperkit
I0223 17:44:13.740422 12805 main.go:141] libmachine: Plugin server listening at address 127.0.0.1:56682
I0223 17:44:13.740765 12805 main.go:141] libmachine: () Calling .GetVersion
I0223 17:44:13.741156 12805 main.go:141] libmachine: Using API Version 1
I0223 17:44:13.741174 12805 main.go:141] libmachine: () Calling .SetConfigRaw
I0223 17:44:13.741370 12805 main.go:141] libmachine: () Calling .GetMachineName
I0223 17:44:13.741493 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
I0223 17:44:13.741589 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetState
I0223 17:44:13.741669 12805 main.go:141] libmachine: (newest-cni-829000) DBG | exe=/Users/jenkins/workspace/out/docker-machine-driver-hyperkit uid=0
I0223 17:44:13.741749 12805 main.go:141] libmachine: (newest-cni-829000) DBG | hyperkit pid from json: 12722
I0223 17:44:13.742591 12805 main.go:141] libmachine: (newest-cni-829000) DBG | hyperkit pid 12722 missing from process table
I0223 17:44:13.742616 12805 fix.go:103] recreateIfNeeded on newest-cni-829000: state=Stopped err=<nil>
I0223 17:44:13.742634 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
W0223 17:44:13.742731 12805 fix.go:129] unexpected machine state, will restart: <nil>
I0223 17:44:13.784619 12805 out.go:177] * Restarting existing hyperkit VM for "newest-cni-829000" ...
I0223 17:44:13.807992 12805 main.go:141] libmachine: (newest-cni-829000) Calling .Start
I0223 17:44:13.808374 12805 main.go:141] libmachine: (newest-cni-829000) DBG | exe=/Users/jenkins/workspace/out/docker-machine-driver-hyperkit uid=0
I0223 17:44:13.808423 12805 main.go:141] libmachine: (newest-cni-829000) minikube might have been shutdown in an unclean way, the hyperkit pid file still exists: /Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/hyperkit.pid
I0223 17:44:13.810173 12805 main.go:141] libmachine: (newest-cni-829000) DBG | hyperkit pid 12722 missing from process table
I0223 17:44:13.810198 12805 main.go:141] libmachine: (newest-cni-829000) DBG | pid 12722 is in state "Stopped"
I0223 17:44:13.810216 12805 main.go:141] libmachine: (newest-cni-829000) DBG | Removing stale pid file /Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/hyperkit.pid...
I0223 17:44:13.810352 12805 main.go:141] libmachine: (newest-cni-829000) DBG | Using UUID 985e7872-b3e4-11ed-a49a-f01898ef957c
I0223 17:44:13.837041 12805 main.go:141] libmachine: (newest-cni-829000) DBG | Generated MAC b2:fd:db:49:fb:c4
I0223 17:44:13.837063 12805 main.go:141] libmachine: (newest-cni-829000) 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=newest-cni-829000
I0223 17:44:13.837215 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 DEBUG: hyperkit: Start &hyperkit.HyperKit{HyperKit:"/usr/local/bin/hyperkit", Argv0:"", StateDir:"/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000", VPNKitSock:"", VPNKitUUID:"", VPNKitPreferredIPv4:"", UUID:"985e7872-b3e4-11ed-a49a-f01898ef957c", Disks:[]hyperkit.Disk{(*hyperkit.RawDisk)(0xc0003e3aa0)}, ISOImages:[]string{"/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/boot2docker.iso"}, VSock:false, VSockDir:"", VSockPorts:[]int(nil), VSockGuestCID:3, VMNet:true, Sockets9P:[]hyperkit.Socket9P(nil), Kernel:"/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/bzimage", Initrd:"/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/initrd", Bootrom:"", CPUs:2, Memory:2200, Console:1, Serials:[]hyperkit.Serial(nil), Pid:0, Arguments:[]string(nil), CmdLine:"", process:(*os.Proc
ess)(nil)}
I0223 17:44:13.837261 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 DEBUG: hyperkit: check &hyperkit.HyperKit{HyperKit:"/usr/local/bin/hyperkit", Argv0:"", StateDir:"/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000", VPNKitSock:"", VPNKitUUID:"", VPNKitPreferredIPv4:"", UUID:"985e7872-b3e4-11ed-a49a-f01898ef957c", Disks:[]hyperkit.Disk{(*hyperkit.RawDisk)(0xc0003e3aa0)}, ISOImages:[]string{"/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/boot2docker.iso"}, VSock:false, VSockDir:"", VSockPorts:[]int(nil), VSockGuestCID:3, VMNet:true, Sockets9P:[]hyperkit.Socket9P(nil), Kernel:"/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/bzimage", Initrd:"/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/initrd", Bootrom:"", CPUs:2, Memory:2200, Console:1, Serials:[]hyperkit.Serial(nil), Pid:0, Arguments:[]string(nil), CmdLine:"", process:(*os.Proc
ess)(nil)}
I0223 17:44:13.837302 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 DEBUG: hyperkit: Arguments: []string{"-A", "-u", "-F", "/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/hyperkit.pid", "-c", "2", "-m", "2200M", "-s", "0:0,hostbridge", "-s", "31,lpc", "-s", "1:0,virtio-net", "-U", "985e7872-b3e4-11ed-a49a-f01898ef957c", "-s", "2:0,virtio-blk,/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/newest-cni-829000.rawdisk", "-s", "3,ahci-cd,/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/boot2docker.iso", "-s", "4,virtio-rnd", "-l", "com1,autopty=/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/tty,log=/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/console-ring", "-f", "kexec,/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/bzimage,/Users/jenkins/minikube-integration/15
909-975/.minikube/machines/newest-cni-829000/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=newest-cni-829000"}
I0223 17:44:13.837347 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 DEBUG: hyperkit: CmdLine: "/usr/local/bin/hyperkit -A -u -F /Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/hyperkit.pid -c 2 -m 2200M -s 0:0,hostbridge -s 31,lpc -s 1:0,virtio-net -U 985e7872-b3e4-11ed-a49a-f01898ef957c -s 2:0,virtio-blk,/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/newest-cni-829000.rawdisk -s 3,ahci-cd,/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/boot2docker.iso -s 4,virtio-rnd -l com1,autopty=/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/tty,log=/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/console-ring -f kexec,/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/bzimage,/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/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=newest-cni-829000"
I0223 17:44:13.837368 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 DEBUG: hyperkit: Redirecting stdout/stderr to logger
I0223 17:44:13.838550 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 DEBUG: hyperkit: Pid is 12818
I0223 17:44:13.838889 12805 main.go:141] libmachine: (newest-cni-829000) DBG | Attempt 0
I0223 17:44:13.838912 12805 main.go:141] libmachine: (newest-cni-829000) DBG | exe=/Users/jenkins/workspace/out/docker-machine-driver-hyperkit uid=0
I0223 17:44:13.838955 12805 main.go:141] libmachine: (newest-cni-829000) DBG | hyperkit pid from json: 12818
I0223 17:44:13.840829 12805 main.go:141] libmachine: (newest-cni-829000) DBG | Searching for b2:fd:db:49:fb:c4 in /var/db/dhcpd_leases ...
I0223 17:44:13.840905 12805 main.go:141] libmachine: (newest-cni-829000) DBG | Found 43 entries in /var/db/dhcpd_leases!
I0223 17:44:13.840918 12805 main.go:141] libmachine: (newest-cni-829000) DBG | dhcp entry: {Name:minikube IPAddress:192.168.64.44 HWAddress:b2:fd:db:49:fb:c4 ID:1,b2:fd:db:49:fb:c4 Lease:0x63f967b7}
I0223 17:44:13.840927 12805 main.go:141] libmachine: (newest-cni-829000) DBG | Found match: b2:fd:db:49:fb:c4
I0223 17:44:13.840935 12805 main.go:141] libmachine: (newest-cni-829000) DBG | IP: 192.168.64.44
I0223 17:44:13.841013 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetConfigRaw
I0223 17:44:13.841588 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetIP
I0223 17:44:13.841760 12805 profile.go:148] Saving config to /Users/jenkins/minikube-integration/15909-975/.minikube/profiles/newest-cni-829000/config.json ...
I0223 17:44:13.842078 12805 machine.go:88] provisioning docker machine ...
I0223 17:44:13.842088 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
I0223 17:44:13.842189 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetMachineName
I0223 17:44:13.842312 12805 buildroot.go:166] provisioning hostname "newest-cni-829000"
I0223 17:44:13.842323 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetMachineName
I0223 17:44:13.842411 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:13.842502 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHPort
I0223 17:44:13.842581 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:13.842664 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:13.842735 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHUsername
I0223 17:44:13.842838 12805 main.go:141] libmachine: Using SSH client type: native
I0223 17:44:13.843203 12805 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140f720] 0x1412660 <nil> [] 0s} 192.168.64.44 22 <nil> <nil>}
I0223 17:44:13.843213 12805 main.go:141] libmachine: About to run SSH command:
sudo hostname newest-cni-829000 && echo "newest-cni-829000" | sudo tee /etc/hostname
I0223 17:44:13.845109 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 INFO : hyperkit: stderr: Using fd 5 for I/O notifications
I0223 17:44:13.852988 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 INFO : hyperkit: stderr: /Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/boot2docker.iso: fcntl(F_PUNCHHOLE) Operation not permitted: block device will not support TRIM/DISCARD
I0223 17:44:13.853658 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 2 bit: 22 unspecified don't care: bit is 0
I0223 17:44:13.853674 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 4 bit: 12 unspecified don't care: bit is 0
I0223 17:44:13.853698 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 4 bit: 20 unspecified don't care: bit is 0
I0223 17:44:13.853712 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:13 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 3 bit: 13 unspecified don't care: bit is 0
I0223 17:44:14.222195 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:14 INFO : hyperkit: stderr: rdmsr to register 0x3a on vcpu 0
I0223 17:44:14.222209 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:14 INFO : hyperkit: stderr: rdmsr to register 0x140 on vcpu 0
I0223 17:44:14.326546 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:14 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 2 bit: 22 unspecified don't care: bit is 0
I0223 17:44:14.326562 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:14 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 4 bit: 12 unspecified don't care: bit is 0
I0223 17:44:14.326570 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:14 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 4 bit: 20 unspecified don't care: bit is 0
I0223 17:44:14.326588 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:14 INFO : hyperkit: stderr: vmx_set_ctlreg: cap_field: 3 bit: 13 unspecified don't care: bit is 0
I0223 17:44:14.327178 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:14 INFO : hyperkit: stderr: rdmsr to register 0x3a on vcpu 1
I0223 17:44:14.327186 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:14 INFO : hyperkit: stderr: rdmsr to register 0x140 on vcpu 1
I0223 17:44:18.896090 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:18 INFO : hyperkit: stderr: rdmsr to register 0x64d on vcpu 1
I0223 17:44:18.896170 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:18 INFO : hyperkit: stderr: rdmsr to register 0x64e on vcpu 1
I0223 17:44:18.896179 12805 main.go:141] libmachine: (newest-cni-829000) DBG | 2023/02/23 17:44:18 INFO : hyperkit: stderr: rdmsr to register 0x34 on vcpu 1
I0223 17:44:27.017975 12805 main.go:141] libmachine: SSH cmd err, output: <nil>: newest-cni-829000
I0223 17:44:27.017993 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:27.018126 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHPort
I0223 17:44:27.018231 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.018313 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.018400 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHUsername
I0223 17:44:27.018536 12805 main.go:141] libmachine: Using SSH client type: native
I0223 17:44:27.018857 12805 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140f720] 0x1412660 <nil> [] 0s} 192.168.64.44 22 <nil> <nil>}
I0223 17:44:27.018869 12805 main.go:141] libmachine: About to run SSH command:
if ! grep -xq '.*\snewest-cni-829000' /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 newest-cni-829000/g' /etc/hosts;
else
echo '127.0.1.1 newest-cni-829000' | sudo tee -a /etc/hosts;
fi
fi
I0223 17:44:27.086771 12805 main.go:141] libmachine: SSH cmd err, output: <nil>:
I0223 17:44:27.086790 12805 buildroot.go:172] set auth options {CertDir:/Users/jenkins/minikube-integration/15909-975/.minikube CaCertPath:/Users/jenkins/minikube-integration/15909-975/.minikube/certs/ca.pem CaPrivateKeyPath:/Users/jenkins/minikube-integration/15909-975/.minikube/certs/ca-key.pem CaCertRemotePath:/etc/docker/ca.pem ServerCertPath:/Users/jenkins/minikube-integration/15909-975/.minikube/machines/server.pem ServerKeyPath:/Users/jenkins/minikube-integration/15909-975/.minikube/machines/server-key.pem ClientKeyPath:/Users/jenkins/minikube-integration/15909-975/.minikube/certs/key.pem ServerCertRemotePath:/etc/docker/server.pem ServerKeyRemotePath:/etc/docker/server-key.pem ClientCertPath:/Users/jenkins/minikube-integration/15909-975/.minikube/certs/cert.pem ServerCertSANs:[] StorePath:/Users/jenkins/minikube-integration/15909-975/.minikube}
I0223 17:44:27.086803 12805 buildroot.go:174] setting up certificates
I0223 17:44:27.086813 12805 provision.go:83] configureAuth start
I0223 17:44:27.086824 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetMachineName
I0223 17:44:27.086970 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetIP
I0223 17:44:27.087068 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:27.087182 12805 provision.go:138] copyHostCerts
I0223 17:44:27.087263 12805 exec_runner.go:144] found /Users/jenkins/minikube-integration/15909-975/.minikube/ca.pem, removing ...
I0223 17:44:27.087273 12805 exec_runner.go:207] rm: /Users/jenkins/minikube-integration/15909-975/.minikube/ca.pem
I0223 17:44:27.087427 12805 exec_runner.go:151] cp: /Users/jenkins/minikube-integration/15909-975/.minikube/certs/ca.pem --> /Users/jenkins/minikube-integration/15909-975/.minikube/ca.pem (1078 bytes)
I0223 17:44:27.087694 12805 exec_runner.go:144] found /Users/jenkins/minikube-integration/15909-975/.minikube/cert.pem, removing ...
I0223 17:44:27.087701 12805 exec_runner.go:207] rm: /Users/jenkins/minikube-integration/15909-975/.minikube/cert.pem
I0223 17:44:27.087767 12805 exec_runner.go:151] cp: /Users/jenkins/minikube-integration/15909-975/.minikube/certs/cert.pem --> /Users/jenkins/minikube-integration/15909-975/.minikube/cert.pem (1123 bytes)
I0223 17:44:27.087929 12805 exec_runner.go:144] found /Users/jenkins/minikube-integration/15909-975/.minikube/key.pem, removing ...
I0223 17:44:27.087939 12805 exec_runner.go:207] rm: /Users/jenkins/minikube-integration/15909-975/.minikube/key.pem
I0223 17:44:27.088037 12805 exec_runner.go:151] cp: /Users/jenkins/minikube-integration/15909-975/.minikube/certs/key.pem --> /Users/jenkins/minikube-integration/15909-975/.minikube/key.pem (1675 bytes)
I0223 17:44:27.088176 12805 provision.go:112] generating server cert: /Users/jenkins/minikube-integration/15909-975/.minikube/machines/server.pem ca-key=/Users/jenkins/minikube-integration/15909-975/.minikube/certs/ca.pem private-key=/Users/jenkins/minikube-integration/15909-975/.minikube/certs/ca-key.pem org=jenkins.newest-cni-829000 san=[192.168.64.44 192.168.64.44 localhost 127.0.0.1 minikube newest-cni-829000]
I0223 17:44:27.162974 12805 provision.go:172] copyRemoteCerts
I0223 17:44:27.163033 12805 ssh_runner.go:195] Run: sudo mkdir -p /etc/docker /etc/docker /etc/docker
I0223 17:44:27.163050 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:27.163198 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHPort
I0223 17:44:27.163301 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.163404 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHUsername
I0223 17:44:27.163494 12805 sshutil.go:53] new ssh client: &{IP:192.168.64.44 Port:22 SSHKeyPath:/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/id_rsa Username:docker}
I0223 17:44:27.197981 12805 ssh_runner.go:362] scp /Users/jenkins/minikube-integration/15909-975/.minikube/certs/ca.pem --> /etc/docker/ca.pem (1078 bytes)
I0223 17:44:27.213188 12805 ssh_runner.go:362] scp /Users/jenkins/minikube-integration/15909-975/.minikube/machines/server.pem --> /etc/docker/server.pem (1229 bytes)
I0223 17:44:27.228193 12805 ssh_runner.go:362] scp /Users/jenkins/minikube-integration/15909-975/.minikube/machines/server-key.pem --> /etc/docker/server-key.pem (1675 bytes)
I0223 17:44:27.243230 12805 provision.go:86] duration metric: configureAuth took 156.403577ms
I0223 17:44:27.243246 12805 buildroot.go:189] setting minikube options for container-runtime
I0223 17:44:27.243389 12805 config.go:182] Loaded profile config "newest-cni-829000": Driver=hyperkit, ContainerRuntime=docker, KubernetesVersion=v1.26.1
I0223 17:44:27.243405 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
I0223 17:44:27.243544 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:27.243639 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHPort
I0223 17:44:27.243736 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.243831 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.243917 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHUsername
I0223 17:44:27.244041 12805 main.go:141] libmachine: Using SSH client type: native
I0223 17:44:27.244340 12805 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140f720] 0x1412660 <nil> [] 0s} 192.168.64.44 22 <nil> <nil>}
I0223 17:44:27.244349 12805 main.go:141] libmachine: About to run SSH command:
df --output=fstype / | tail -n 1
I0223 17:44:27.302245 12805 main.go:141] libmachine: SSH cmd err, output: <nil>: tmpfs
I0223 17:44:27.302263 12805 buildroot.go:70] root file system type: tmpfs
I0223 17:44:27.302353 12805 provision.go:309] Updating docker unit: /lib/systemd/system/docker.service ...
I0223 17:44:27.302368 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:27.302504 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHPort
I0223 17:44:27.302601 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.302675 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.302758 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHUsername
I0223 17:44:27.302885 12805 main.go:141] libmachine: Using SSH client type: native
I0223 17:44:27.303220 12805 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140f720] 0x1412660 <nil> [] 0s} 192.168.64.44 22 <nil> <nil>}
I0223 17:44:27.303270 12805 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
I0223 17:44:27.370180 12805 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
I0223 17:44:27.370198 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:27.370344 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHPort
I0223 17:44:27.370441 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.370528 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.370618 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHUsername
I0223 17:44:27.370741 12805 main.go:141] libmachine: Using SSH client type: native
I0223 17:44:27.371049 12805 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140f720] 0x1412660 <nil> [] 0s} 192.168.64.44 22 <nil> <nil>}
I0223 17:44:27.371061 12805 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; }
I0223 17:44:27.900888 12805 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.
I0223 17:44:27.900901 12805 machine.go:91] provisioned docker machine in 14.058742531s
I0223 17:44:27.900912 12805 start.go:300] post-start starting for "newest-cni-829000" (driver="hyperkit")
I0223 17:44:27.900917 12805 start.go:328] 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]
I0223 17:44:27.900927 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
I0223 17:44:27.901133 12805 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
I0223 17:44:27.901146 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:27.901251 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHPort
I0223 17:44:27.901352 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.901458 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHUsername
I0223 17:44:27.901554 12805 sshutil.go:53] new ssh client: &{IP:192.168.64.44 Port:22 SSHKeyPath:/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/id_rsa Username:docker}
I0223 17:44:27.937812 12805 ssh_runner.go:195] Run: cat /etc/os-release
I0223 17:44:27.940572 12805 info.go:137] Remote host: Buildroot 2021.02.12
I0223 17:44:27.940587 12805 filesync.go:126] Scanning /Users/jenkins/minikube-integration/15909-975/.minikube/addons for local assets ...
I0223 17:44:27.940682 12805 filesync.go:126] Scanning /Users/jenkins/minikube-integration/15909-975/.minikube/files for local assets ...
I0223 17:44:27.940834 12805 filesync.go:149] local asset: /Users/jenkins/minikube-integration/15909-975/.minikube/files/etc/ssl/certs/22062.pem -> 22062.pem in /etc/ssl/certs
I0223 17:44:27.940996 12805 ssh_runner.go:195] Run: sudo mkdir -p /etc/ssl/certs
I0223 17:44:27.946950 12805 ssh_runner.go:362] scp /Users/jenkins/minikube-integration/15909-975/.minikube/files/etc/ssl/certs/22062.pem --> /etc/ssl/certs/22062.pem (1708 bytes)
I0223 17:44:27.963515 12805 start.go:303] post-start completed in 62.593671ms
I0223 17:44:27.963536 12805 fix.go:57] fixHost completed within 14.231151284s
I0223 17:44:27.963551 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:27.963688 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHPort
I0223 17:44:27.963763 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.963853 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:27.963928 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHUsername
I0223 17:44:27.964068 12805 main.go:141] libmachine: Using SSH client type: native
I0223 17:44:27.964381 12805 main.go:141] libmachine: &{{{<nil> 0 [] [] []} docker [0x140f720] 0x1412660 <nil> [] 0s} 192.168.64.44 22 <nil> <nil>}
I0223 17:44:27.964389 12805 main.go:141] libmachine: About to run SSH command:
date +%s.%N
I0223 17:44:28.021863 12805 main.go:141] libmachine: SSH cmd err, output: <nil>: 1677203067.777296298
I0223 17:44:28.021874 12805 fix.go:207] guest clock: 1677203067.777296298
I0223 17:44:28.021880 12805 fix.go:220] Guest: 2023-02-23 17:44:27.777296298 -0800 PST Remote: 2023-02-23 17:44:27.96354 -0800 PST m=+14.665742271 (delta=-186.243702ms)
I0223 17:44:28.021901 12805 fix.go:191] guest clock delta is within tolerance: -186.243702ms
I0223 17:44:28.021906 12805 start.go:83] releasing machines lock for "newest-cni-829000", held for 14.289575164s
I0223 17:44:28.021927 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
I0223 17:44:28.022053 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetIP
I0223 17:44:28.022150 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
I0223 17:44:28.022432 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
I0223 17:44:28.022570 12805 main.go:141] libmachine: (newest-cni-829000) Calling .DriverName
I0223 17:44:28.022666 12805 ssh_runner.go:195] Run: curl -sS -m 2 https://registry.k8s.io/
I0223 17:44:28.022695 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:28.022709 12805 ssh_runner.go:195] Run: cat /version.json
I0223 17:44:28.022721 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHHostname
I0223 17:44:28.022800 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHPort
I0223 17:44:28.022825 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHPort
I0223 17:44:28.022890 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:28.022921 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHKeyPath
I0223 17:44:28.023009 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHUsername
I0223 17:44:28.023024 12805 main.go:141] libmachine: (newest-cni-829000) Calling .GetSSHUsername
I0223 17:44:28.023109 12805 sshutil.go:53] new ssh client: &{IP:192.168.64.44 Port:22 SSHKeyPath:/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/id_rsa Username:docker}
I0223 17:44:28.023121 12805 sshutil.go:53] new ssh client: &{IP:192.168.64.44 Port:22 SSHKeyPath:/Users/jenkins/minikube-integration/15909-975/.minikube/machines/newest-cni-829000/id_rsa Username:docker}
I0223 17:44:28.054661 12805 ssh_runner.go:195] Run: systemctl --version
I0223 17:44:28.099020 12805 ssh_runner.go:195] Run: sh -c "stat /etc/cni/net.d/*loopback.conf*"
W0223 17:44:28.103197 12805 cni.go:208] loopback cni configuration skipped: "/etc/cni/net.d/*loopback.conf*" not found
I0223 17:44:28.103242 12805 ssh_runner.go:195] Run: which cri-dockerd
I0223 17:44:28.105716 12805 ssh_runner.go:195] Run: sudo mkdir -p /etc/systemd/system/cri-docker.service.d
I0223 17:44:28.112008 12805 ssh_runner.go:362] scp memory --> /etc/systemd/system/cri-docker.service.d/10-cni.conf (135 bytes)
I0223 17:44:28.123178 12805 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" ;
I0223 17:44:28.134144 12805 cni.go:261] disabled [/etc/cni/net.d/87-podman-bridge.conflist] bridge cni config(s)
I0223 17:44:28.134161 12805 preload.go:132] Checking if preload exists for k8s version v1.26.1 and runtime docker
I0223 17:44:28.134254 12805 ssh_runner.go:195] Run: docker images --format {{.Repository}}:{{.Tag}}
I0223 17:44:28.151089 12805 docker.go:630] Got preloaded images: -- stdout --
registry.k8s.io/kube-apiserver:v1.26.1
registry.k8s.io/kube-scheduler:v1.26.1
registry.k8s.io/kube-controller-manager:v1.26.1
registry.k8s.io/kube-proxy:v1.26.1
registry.k8s.io/etcd:3.5.6-0
registry.k8s.io/pause:3.9
registry.k8s.io/coredns/coredns:v1.9.3
registry.k8s.io/pause:3.6
gcr.io/k8s-minikube/storage-provisioner:v5
-- /stdout --
I0223 17:44:28.151102 12805 docker.go:560] Images already preloaded, skipping extraction
I0223 17:44:28.151109 12805 start.go:485] detecting cgroup driver to use...
I0223 17:44:28.151189 12805 ssh_runner.go:195] Run: /bin/bash -c "sudo mkdir -p /etc && printf %s "runtime-endpoint: unix:///run/containerd/containerd.sock
image-endpoint: unix:///run/containerd/containerd.sock
" | sudo tee /etc/crictl.yaml"
I0223 17:44:28.163171 12805 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"
I0223 17:44:28.170338 12805 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"
I0223 17:44:28.177550 12805 containerd.go:145] configuring containerd to use "cgroupfs" as cgroup driver...
I0223 17:44:28.177599 12805 ssh_runner.go:195] Run: sh -c "sudo sed -i -r 's|^( *)SystemdCgroup = .*$|\1SystemdCgroup = false|g' /etc/containerd/config.toml"
I0223 17:44:28.184675 12805 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"
I0223 17:44:28.191589 12805 ssh_runner.go:195] Run: sh -c "sudo sed -i '/systemd_cgroup/d' /etc/containerd/config.toml"
I0223 17:44:28.198494 12805 ssh_runner.go:195] Run: sh -c "sudo sed -i 's|"io.containerd.runc.v1"|"io.containerd.runc.v2"|g' /etc/containerd/config.toml"
I0223 17:44:28.205485 12805 ssh_runner.go:195] Run: sh -c "sudo rm -rf /etc/cni/net.mk"
I0223 17:44:28.212624 12805 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"
I0223 17:44:28.219724 12805 ssh_runner.go:195] Run: sudo sysctl net.bridge.bridge-nf-call-iptables
I0223 17:44:28.226343 12805 ssh_runner.go:195] Run: sudo sh -c "echo 1 > /proc/sys/net/ipv4/ip_forward"
I0223 17:44:28.232583 12805 ssh_runner.go:195] Run: sudo systemctl daemon-reload
I0223 17:44:28.311041 12805 ssh_runner.go:195] Run: sudo systemctl restart containerd
I0223 17:44:28.324538 12805 start.go:485] detecting cgroup driver to use...
I0223 17:44:28.324614 12805 ssh_runner.go:195] Run: sudo systemctl cat docker.service
I0223 17:44:28.340090 12805 ssh_runner.go:195] Run: sudo systemctl is-active --quiet service containerd
I0223 17:44:28.366333 12805 ssh_runner.go:195] Run: sudo systemctl stop -f containerd
I0223 17:44:28.380004 12805 ssh_runner.go:195] Run: sudo systemctl is-active --quiet service containerd
I0223 17:44:28.388556 12805 ssh_runner.go:195] Run: sudo systemctl is-active --quiet service crio
I0223 17:44:28.396844 12805 ssh_runner.go:195] Run: sudo systemctl stop -f crio
I0223 17:44:28.413187 12805 ssh_runner.go:195] Run: sudo systemctl is-active --quiet service crio
I0223 17:44:28.422606 12805 ssh_runner.go:195] Run: /bin/bash -c "sudo mkdir -p /etc && printf %s "runtime-endpoint: unix:///var/run/cri-dockerd.sock
image-endpoint: unix:///var/run/cri-dockerd.sock
" | sudo tee /etc/crictl.yaml"
I0223 17:44:28.434730 12805 ssh_runner.go:195] Run: sudo systemctl unmask docker.service
I0223 17:44:28.522142 12805 ssh_runner.go:195] Run: sudo systemctl enable docker.socket
I0223 17:44:28.617259 12805 docker.go:529] configuring docker to use "cgroupfs" as cgroup driver...
I0223 17:44:28.617276 12805 ssh_runner.go:362] scp memory --> /etc/docker/daemon.json (144 bytes)
I0223 17:44:28.630202 12805 ssh_runner.go:195] Run: sudo systemctl daemon-reload
I0223 17:44:28.725359 12805 ssh_runner.go:195] Run: sudo systemctl restart docker
I0223 17:45:29.451165 12805 ssh_runner.go:235] Completed: sudo systemctl restart docker: (1m0.725465849s)
I0223 17:45:29.472022 12805 out.go:177]
W0223 17:45:29.492842 12805 out.go:239] X Exiting due to RUNTIME_ENABLE: 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: 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.
W0223 17:45:29.492854 12805 out.go:239] *
*
W0223 17:45:29.493481 12805 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. │
│ │
╰─────────────────────────────────────────────────────────────────────────────────────────────╯
I0223 17:45:29.576685 12805 out.go:177]
** /stderr **
start_stop_delete_test.go:259: failed to start minikube post-stop. args "out/minikube-darwin-amd64 start -p newest-cni-829000 --memory=2200 --alsologtostderr --wait=apiserver,system_pods,default_sa --feature-gates ServerSideApply=true --network-plugin=cni --extra-config=kubeadm.pod-network-cidr=10.42.0.0/16 --driver=hyperkit --kubernetes-version=v1.26.1": exit status 90
helpers_test.go:222: -----------------------post-mortem--------------------------------
helpers_test.go:239: (dbg) Run: out/minikube-darwin-amd64 status --format={{.Host}} -p newest-cni-829000 -n newest-cni-829000
helpers_test.go:239: (dbg) Non-zero exit: out/minikube-darwin-amd64 status --format={{.Host}} -p newest-cni-829000 -n newest-cni-829000: exit status 6 (124.696325ms)
-- stdout --
Running
WARNING: Your kubectl is pointing to stale minikube-vm.
To fix the kubectl context, run `minikube update-context`
-- /stdout --
** stderr **
E0223 17:45:29.744698 12900 status.go:415] kubeconfig endpoint: extract IP: "newest-cni-829000" does not appear in /Users/jenkins/minikube-integration/15909-975/kubeconfig
** /stderr **
helpers_test.go:239: status error: exit status 6 (may be ok)
helpers_test.go:241: "newest-cni-829000" 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/newest-cni/serial/SecondStart (76.46s)