Minikube Integration Testing (Work in progress)
This article will outline few things that are helpful when running or modifying minikube testing code.
- Make sure kubectl is in the PATH
Following command is to disable parallel testing and enable all log output
the test.v parameter instruct the testing framework to output non-failure messages. The output will not be realtime as it will only be outputted when the test complete.-parallel 1 -test.v
To run the test use the following command
The /home/nanik/Downloads is added to the PATH because that’s the location for kubectl and the test cases uses kubectl.PATH=/home/nanik/Golang/go/bin:/home/nanik/Downloads:/home/nanik/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/snap/bin:/var/lib/snapd/snap/bin:/home/nanik/Downloads/ go test -test.v -tags integration
DO NOT USE -parrallel 1 when running ALL the test cases as for some reason it throws an error.
Running make integration command will yield output similar to the following
GOOS="linux" GOARCH="amd64" go build -tags "container_image_ostree_stub containers_image_openpgp go_getter_nos3 go_getter_nogcs" -ldflags="-X k8s.io/minikube/pkg/version.version=v1.5.2 -X k8s.io/minikube/pkg/version.isoVersion=v1.5.1 -X k8s.io/minikube/pkg/version.isoPath=minikube/iso -X k8s.io/minikube/pkg/version.gitCommitID="3322c50ceb4abf795ebb8505f99bbb269a144e21-dirty"" -a -o out/minikube-linux-amd64 k8s.io/minikube/cmd/minikube cp out/minikube-linux-amd64 out/minikube go test -v -test.timeout=60m ./test/integration --tags="integration container_image_ostree_stub containers_image_openpgp go_getter_nos3 go_getter_nogcs" === RUN TestDownloadOnly === RUN TestDownloadOnly/group === RUN TestDownloadOnly/group/v1.11.10 === RUN TestDownloadOnly/group/v1.16.2 === RUN TestDownloadOnly/group/v1.16.2#01 === RUN TestDownloadOnly/group/ExpectedDefaultDriver === RUN TestDownloadOnly/group/DeleteAll === RUN TestDownloadOnly/group/DeleteAlwaysSucceeds --- PASS: TestDownloadOnly (33.63s) --- PASS: TestDownloadOnly/group (33.57s) --- PASS: TestDownloadOnly/group/v1.11.10 (19.74s) a_serial_test.go:61: (dbg) Run: out/minikube start --download-only -p download-20191104T082052.238721463-18873 --force --alsologtostderr --kubernetes-version=v1.11.10 a_serial_test.go:61: (dbg) Done: out/minikube start --download-only -p download-20191104T082052.238721463-18873 --force --alsologtostderr --kubernetes-version=v1.11.10: (19.741382231s) --- PASS: TestDownloadOnly/group/v1.16.2 (13.46s) a_serial_test.go:63: (dbg) Run: out/minikube start --download-only -p download-20191104T082052.238721463-18873 --force --alsologtostderr --kubernetes-version=v1.16.2 a_serial_test.go:63: (dbg) Done: out/minikube start --download-only -p download-20191104T082052.238721463-18873 --force --alsologtostderr --kubernetes-version=v1.16.2: (13.460844164s) --- PASS: TestDownloadOnly/group/v1.16.2#01 (0.27s) a_serial_test.go:63: (dbg) Run: out/minikube start --download-only -p download-20191104T082052.238721463-18873 --force --alsologtostderr --kubernetes-version=v1.16.2 --- SKIP: TestDownloadOnly/group/ExpectedDefaultDriver (0.00s) a_serial_test.go:94: --expected-default-driver is unset, skipping test --- PASS: TestDownloadOnly/group/DeleteAll (0.06s) a_serial_test.go:124: (dbg) Run: out/minikube delete --all --- PASS: TestDownloadOnly/group/DeleteAlwaysSucceeds (0.03s) a_serial_test.go:134: (dbg) Run: out/minikube delete -p download-20191104T082052.238721463-18873 helpers.go:167: (dbg) Run: out/minikube delete -p download-20191104T082052.238721463-18873 === RUN TestAddons === PAUSE TestAddons === RUN TestDockerFlags === PAUSE TestDockerFlags === RUN TestKVMDriverInstallOrUpdate === PAUSE TestKVMDriverInstallOrUpdate === RUN TestHyperKitDriverInstallOrUpdate --- SKIP: TestHyperKitDriverInstallOrUpdate (0.00s) driver_install_or_update_test.go:101: Skip if not darwin. === RUN TestFunctional === RUN TestFunctional/serial === RUN TestFunctional/serial/StartWithProxy === RUN TestFunctional/serial/KubeContext === RUN TestFunctional/serial/KubectlGetPods === RUN TestFunctional/serial/CacheCmd === PAUSE TestFunctional === RUN TestGvisorAddon --- SKIP: TestGvisorAddon (0.00s) gvisor_addon_test.go:34: skipping test because --gvisor=false === RUN TestChangeNoneUser --- SKIP: TestChangeNoneUser (0.00s) none_test.go:39: Only test none driver. === RUN TestStartStop === PAUSE TestStartStop === RUN TestVersionUpgrade === PAUSE TestVersionUpgrade === CONT TestAddons === CONT TestStartStop === CONT TestFunctional === CONT TestVersionUpgrade === CONT TestDockerFlags === RUN TestFunctional/parallel === CONT TestKVMDriverInstallOrUpdate === RUN TestFunctional/parallel/AddonManager === RUN TestStartStop/group === PAUSE TestFunctional/parallel/AddonManager === RUN TestFunctional/parallel/ComponentHealth === PAUSE TestFunctional/parallel/ComponentHealth === RUN TestStartStop/group/docker === RUN TestFunctional/parallel/ConfigCmd === PAUSE TestFunctional/parallel/ConfigCmd === RUN TestFunctional/parallel/DashboardCmd === PAUSE TestStartStop/group/docker === RUN TestStartStop/group/cni === PAUSE TestFunctional/parallel/DashboardCmd === RUN TestFunctional/parallel/DNS === PAUSE TestStartStop/group/cni === PAUSE TestFunctional/parallel/DNS === RUN TestStartStop/group/containerd === RUN TestFunctional/parallel/StatusCmd === PAUSE TestFunctional/parallel/StatusCmd === PAUSE TestStartStop/group/containerd === RUN TestFunctional/parallel/LogsCmd === RUN TestStartStop/group/crio === PAUSE TestFunctional/parallel/LogsCmd === RUN TestFunctional/parallel/MountCmd === PAUSE TestStartStop/group/crio === CONT TestStartStop/group/docker === PAUSE TestFunctional/parallel/MountCmd === CONT TestStartStop/group/containerd === RUN TestFunctional/parallel/ProfileCmd === CONT TestStartStop/group/crio === CONT TestStartStop/group/cni === PAUSE TestFunctional/parallel/ProfileCmd === RUN TestFunctional/parallel/ServiceCmd === PAUSE TestFunctional/parallel/ServiceCmd === RUN TestFunctional/parallel/AddonsCmd === PAUSE TestFunctional/parallel/AddonsCmd === RUN TestFunctional/parallel/PersistentVolumeClaim === PAUSE TestFunctional/parallel/PersistentVolumeClaim === RUN TestFunctional/parallel/TunnelCmd === PAUSE TestFunctional/parallel/TunnelCmd === RUN TestFunctional/parallel/SSHCmd === PAUSE TestFunctional/parallel/SSHCmd === RUN TestFunctional/parallel/MySQL === PAUSE TestFunctional/parallel/MySQL === CONT TestFunctional/parallel/AddonManager === CONT TestFunctional/parallel/MySQL === CONT TestFunctional/parallel/MountCmd === CONT TestFunctional/parallel/DNS > docker-machine-driver-kvm2.sha256: 65 B / 65 B [-------] 100.00% ? p/s 0s === CONT TestFunctional/parallel/ConfigCmd === CONT TestFunctional/parallel/DashboardCmd === CONT TestFunctional/parallel/LogsCmd === CONT TestFunctional/parallel/ComponentHealth === CONT TestFunctional/parallel/StatusCmd === CONT TestFunctional/parallel/PersistentVolumeClaim > docker-machine-driver-kvm2: 0 B / 48.57 MiB [_____________] 0.00% ? p/s ? > docker-machine-driver-kvm2: 33.55 KiB / 48.57 MiB [>______] 0.07% ? p/s ? > docker-machine-driver-kvm2: 84.55 KiB / 48.57 MiB [>______] 0.17% ? p/s ? > docker-machine-driver-kvm2: 169.55 KiB / 48.57 MiB 0.34% 282.61 KiB p/s > docker-machine-driver-kvm2: 169.55 KiB / 48.57 MiB 0.34% 282.61 KiB p/s > docker-machine-driver-kvm2: 338.52 KiB / 48.57 MiB 0.68% 282.61 KiB p/s > docker-machine-driver-kvm2: 662.55 KiB / 48.57 MiB 1.33% 317.38 KiB p/s === CONT TestFunctional/parallel/SSHCmd > docker-machine-driver-kvm2: 662.55 KiB / 48.57 MiB 1.33% 317.38 KiB p/s === CONT TestFunctional/parallel/TunnelCmd === CONT TestFunctional/parallel/ServiceCmd > docker-machine-driver-kvm2: 1.31 MiB / 48.57 MiB 2.70% 317.38 KiB p/s ET > docker-machine-driver-kvm2: 2.13 MiB / 48.57 MiB 4.38% 459.99 KiB p/s ET > docker-machine-driver-kvm2: 2.30 MiB / 48.57 MiB 4.74% 459.99 KiB p/s ET > docker-machine-driver-kvm2: 3.35 MiB / 48.57 MiB 6.89% 459.99 KiB p/s ET > docker-machine-driver-kvm2: 4.44 MiB / 48.57 MiB 9.14% 684.97 KiB p/s ET > > ..... > ..... === CONT TestFunctional/parallel/AddonsCmd === CONT TestFunctional/parallel/ProfileCmd > docker-machine-driver-kvm2: 21.21 MiB / 48.57 MiB 43.66% 1.86 MiB p/s ET > docker-machine-driver-kvm2: 21.21 MiB / 48.57 MiB 43.66% 2.08 MiB p/s ET > docker-machine-driver-kvm2: 22.78 MiB / 48.57 MiB 46.91% 2.08 MiB p/s ET > docker-machine-driver-kvm2: 23.35 MiB / 48.57 MiB 48.06% 2.08 MiB p/s ET > docker-machine-driver-kvm2: 24.91 MiB / 48.57 MiB 51.28% 2.34 MiB p/s ET > ..... > ..... > ..... 2019/11/04 08:25:30 [DEBUG] GET http://192.168.39.24:31849 2019/11/04 08:25:38 [DEBUG] GET http://127.0.0.1:38193/api/v1/namespaces/kubernetes-dashboard/services/http:kubernetes-dashboard:/proxy/ --- PASS: TestFunctional (254.26s) --- PASS: TestFunctional/serial (206.43s) --- PASS: TestFunctional/serial/StartWithProxy (177.80s) functional_test.go:120: (dbg) Run: out/minikube start -p functional-20191104T082125.872658733-18873 --wait=false functional_test.go:120: (dbg) Done: out/minikube start -p functional-20191104T082125.872658733-18873 --wait=false : (2m57.799561087s) --- PASS: TestFunctional/serial/KubeContext (0.05s) functional_test.go:138: (dbg) Run: kubectl config current-context --- PASS: TestFunctional/serial/KubectlGetPods (0.44s) functional_test.go:149: (dbg) Run: kubectl get pod -A --- PASS: TestFunctional/serial/CacheCmd (28.14s) functional_test.go:302: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 cache add busybox functional_test.go:302: (dbg) Done: out/minikube -p functional-20191104T082125.872658733-18873 cache add busybox: (5.119077944s) functional_test.go:302: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 cache add busybox:1.28.4-glibc functional_test.go:302: (dbg) Done: out/minikube -p functional-20191104T082125.872658733-18873 cache add busybox:1.28.4-glibc: (5.002939096s) functional_test.go:302: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 cache add mysql:5.6 functional_test.go:302: (dbg) Done: out/minikube -p functional-20191104T082125.872658733-18873 cache add mysql:5.6: (18.018114782s) --- PASS: TestFunctional/parallel (0.00s) --- PASS: TestFunctional/parallel/MountCmd (4.77s) fn_mount_cmd.go:62: (dbg) daemon: [../../out/minikube mount -p functional-20191104T082125.872658733-18873 /tmp/mounttest209263981:/mount-9p --alsologtostderr -v=1] fn_mount_cmd.go:96: wrote "test-1572816292301508417" to /tmp/mounttest209263981/created-by-test fn_mount_cmd.go:96: wrote "test-1572816292301508417" to /tmp/mounttest209263981/created-by-test-removed-by-pod fn_mount_cmd.go:96: wrote "test-1572816292301508417" to /tmp/mounttest209263981/test-1572816292301508417 fn_mount_cmd.go:104: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 ssh "findmnt -T /mount-9p | grep 9p" fn_mount_cmd.go:104: (dbg) Non-zero exit: out/minikube -p functional-20191104T082125.872658733-18873 ssh "findmnt -T /mount-9p | grep 9p": exit status 1 (202.701275ms) ** stderr ** ssh: Process exited with status 1 ** /stderr ** fn_mount_cmd.go:104: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 ssh "findmnt -T /mount-9p | grep 9p" fn_mount_cmd.go:118: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 ssh -- ls -la /mount-9p fn_mount_cmd.go:122: guest mount directory contents total 2 -rw-r--r-- 1 docker docker 24 Nov 3 21:24 created-by-test -rw-r--r-- 1 docker docker 24 Nov 3 21:24 created-by-test-removed-by-pod -rw-r--r-- 1 docker docker 24 Nov 3 21:24 test-1572816292301508417 fn_mount_cmd.go:126: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 ssh cat /mount-9p/test-1572816292301508417 fn_mount_cmd.go:137: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 replace --force -f testdata/busybox-mount-test.yaml fn_mount_cmd.go:142: (dbg) waiting for pods with labels "integration-test=busybox-mount" in namespace "default" ... helpers.go:247: "busybox-mount" [cad31f9d-5fe3-423d-b72c-76365e32eaac] Pending helpers.go:247: "busybox-mount" [cad31f9d-5fe3-423d-b72c-76365e32eaac] Pending / Ready:ContainersNotReady (containers with unready status: [mount-munger]) / ContainersReady:ContainersNotReady (containers with unready status: [mount-munger]) helpers.go:247: "busybox-mount" [cad31f9d-5fe3-423d-b72c-76365e32eaac] Succeeded: Initialized:PodCompleted / Ready:PodCompleted / ContainersReady:PodCompleted fn_mount_cmd.go:142: (dbg) pods integration-test=busybox-mount up and healthy within 2.006393812s fn_mount_cmd.go:158: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 logs busybox-mount fn_mount_cmd.go:170: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 ssh stat /mount-9p/created-by-test fn_mount_cmd.go:170: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 ssh stat /mount-9p/created-by-pod fn_mount_cmd.go:79: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 ssh "sudo umount -f /mount-9p" fn_mount_cmd.go:83: (dbg) stopping [../../out/minikube mount -p functional-20191104T082125.872658733-18873 /tmp/mounttest209263981:/mount-9p --alsologtostderr -v=1] ... --- PASS: TestFunctional/parallel/ConfigCmd (0.15s) functional_test.go:326: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 config unset cpus functional_test.go:326: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 config get cpus functional_test.go:326: (dbg) Non-zero exit: out/minikube -p functional-20191104T082125.872658733-18873 config get cpus: exit status 64 (21.49557ms) ** stderr ** Error: specified key could not be found in config ** /stderr ** functional_test.go:326: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 config set cpus 2 functional_test.go:326: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 config get cpus functional_test.go:326: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 config unset cpus functional_test.go:326: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 config get cpus functional_test.go:326: (dbg) Non-zero exit: out/minikube -p functional-20191104T082125.872658733-18873 config get cpus: exit status 64 (19.061597ms) ** stderr ** Error: specified key could not be found in config ** /stderr ** --- PASS: TestFunctional/parallel/AddonManager (5.06s) functional_test.go:162: (dbg) waiting for pods with labels "component=kube-addon-manager" in namespace "kube-system" ... helpers.go:247: "kube-addon-manager-minikube" [713e5c52-a374-40ed-9f57-f14c7d0de26a] Running functional_test.go:162: (dbg) pods component=kube-addon-manager up and healthy within 5.026986587s --- PASS: TestFunctional/parallel/LogsCmd (0.59s) functional_test.go:344: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 logs --- PASS: TestFunctional/parallel/ComponentHealth (0.07s) functional_test.go:169: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 get cs -o=json --- PASS: TestFunctional/parallel/StatusCmd (0.57s) functional_test.go:194: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 status functional_test.go:200: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 status -f host:{{.Host}},kublet:{{.Kubelet}},apiserver:{{.APIServer}},kubeconfig:{{.Kubeconfig}} functional_test.go:210: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 status -o json --- PASS: TestFunctional/parallel/DNS (8.60s) functional_test.go:270: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 replace --force -f testdata/busybox.yaml functional_test.go:275: (dbg) waiting for pods with labels "integration-test=busybox" in namespace "default" ... helpers.go:247: "busybox" [24600016-7278-4daa-8a5d-b54f465d0f19] Pending helpers.go:247: "busybox" [24600016-7278-4daa-8a5d-b54f465d0f19] Pending / Ready:ContainersNotReady (containers with unready status: [busybox]) / ContainersReady:ContainersNotReady (containers with unready status: [busybox]) helpers.go:247: "busybox" [24600016-7278-4daa-8a5d-b54f465d0f19] Running functional_test.go:275: (dbg) pods integration-test=busybox up and healthy within 8.011521017s functional_test.go:281: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 exec busybox nslookup kubernetes.default --- PASS: TestFunctional/parallel/SSHCmd (0.15s) functional_test.go:537: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 ssh "echo hello" --- SKIP: TestFunctional/parallel/TunnelCmd (0.01s) fn_tunnel_cmd.go:47: password required to execute 'route', skipping testTunnel: exit status 1 --- PASS: TestFunctional/parallel/MySQL (12.36s) functional_test.go:548: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 replace --force -f testdata/mysql.yaml functional_test.go:555: (dbg) waiting for pods with labels "app=mysql" in namespace "default" ... helpers.go:247: "mysql-5787d7b5fc-kqdrj" [90a614ba-f2d8-4318-92ae-6edd7463f14c] Pending helpers.go:247: "mysql-5787d7b5fc-kqdrj" [90a614ba-f2d8-4318-92ae-6edd7463f14c] Pending / Ready:ContainersNotReady (containers with unready status: [mysql]) / ContainersReady:ContainersNotReady (containers with unready status: [mysql]) helpers.go:247: "mysql-5787d7b5fc-kqdrj" [90a614ba-f2d8-4318-92ae-6edd7463f14c] Running functional_test.go:555: pod "app=mysql" failed to start: timed out waiting for the condition helpers.go:292: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 get po -A --show-labels helpers.go:298: (dbg) kubectl --context functional-20191104T082125.872658733-18873 get po -A --show-labels: NAMESPACE NAME READY STATUS RESTARTS AGE LABELS default busybox 1/1 Running 0 5s integration-test=busybox default busybox-mount 0/1 Completed 0 3s integration-test=busybox-mount default mysql-5787d7b5fc-kqdrj 1/1 Running 0 5s app=mysql,pod-template-hash=5787d7b5fc kube-system coredns-5644d7b6d9-p9dkz 1/1 Running 0 104s k8s-app=kube-dns,pod-template-hash=5644d7b6d9 kube-system coredns-5644d7b6d9-wbttz 1/1 Running 0 104s k8s-app=kube-dns,pod-template-hash=5644d7b6d9 kube-system etcd-minikube 1/1 Running 0 41s component=etcd,tier=control-plane kube-system kube-addon-manager-minikube 1/1 Running 0 112s component=kube-addon-manager,kubernetes.io/minikube-addons=addon-manager,version=v9.0.2 kube-system kube-apiserver-minikube 1/1 Running 0 34s component=kube-apiserver,tier=control-plane kube-system kube-controller-manager-minikube 1/1 Running 0 37s component=kube-controller-manager,tier=control-plane kube-system kube-proxy-wc5fw 1/1 Running 0 104s controller-revision-hash=56ffd4ff47,k8s-app=kube-proxy,pod-template-generation=1 kube-system kube-scheduler-minikube 1/1 Running 0 26s component=kube-scheduler,tier=control-plane kube-system storage-provisioner 1/1 Running 0 103s addonmanager.kubernetes.io/mode=Reconcile,integration-test=storage-provisioner helpers.go:301: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 describe po mysql-5787d7b5fc-kqdrj -n default helpers.go:305: (dbg) kubectl --context functional-20191104T082125.872658733-18873 describe po mysql-5787d7b5fc-kqdrj -n default: Name: mysql-5787d7b5fc-kqdrj Namespace: default Priority: 0 Node: minikube/192.168.39.24 Start Time: Mon, 04 Nov 2019 08:24:52 +1100 Labels: app=mysql pod-template-hash=5787d7b5fc Annotations: <none> Status: Running IP: 172.17.0.5 Controlled By: ReplicaSet/mysql-5787d7b5fc Containers: mysql: Container ID: docker://38da7fcc7cc8841b3233ef5fc800c8375602336625daf18456b13eafb40ac7d9 Image: mysql:5.6 Image ID: docker://sha256:b3983abaa3feff23bf58b849c7c2c0f84862e3a749a3181a0bdd6fcfa023f318 Port: 3306/TCP Host Port: 0/TCP State: Running Started: Mon, 04 Nov 2019 08:24:54 +1100 Ready: True Restart Count: 0 Environment: MYSQL_ROOT_PASSWORD: password Mounts: /var/run/secrets/kubernetes.io/serviceaccount from default-token-s7jh6 (ro) Conditions: Type Status Initialized True Ready True ContainersReady True PodScheduled True Volumes: default-token-s7jh6: Type: Secret (a volume populated by a Secret) SecretName: default-token-s7jh6 Optional: false QoS Class: BestEffort Node-Selectors: <none> Tolerations: node.kubernetes.io/not-ready:NoExecute for 300s node.kubernetes.io/unreachable:NoExecute for 300s Events: Type Reason Age From Message ---- ------ ---- ---- ------- Normal Scheduled <unknown> default-scheduler Successfully assigned default/mysql-5787d7b5fc-kqdrj to minikube Normal Pulled 4s kubelet, minikube Container image "mysql:5.6" already present on machine Normal Created 4s kubelet, minikube Created container mysql Normal Started 3s kubelet, minikube Started container mysql helpers.go:308: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 logs mysql-5787d7b5fc-kqdrj -n default helpers.go:312: (dbg) kubectl --context functional-20191104T082125.872658733-18873 logs mysql-5787d7b5fc-kqdrj -n default: 2019-11-03 21:24:54+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.6.46-1debian9 started. 2019-11-03 21:24:54+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql' 2019-11-03 21:24:54+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.6.46-1debian9 started. 2019-11-03 21:24:54+00:00 [Note] [Entrypoint]: Initializing database files 2019-11-03 21:24:54 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2019-11-03 21:24:54 0 [Note] Ignoring --secure-file-priv value as server is running with --bootstrap. 2019-11-03 21:24:54 0 [Note] /usr/sbin/mysqld (mysqld 5.6.46) starting as process 49 ... 2019-11-03 21:24:54 49 [Note] InnoDB: Using atomics to ref count buffer pool pages 2019-11-03 21:24:54 49 [Note] InnoDB: The InnoDB memory heap is disabled 2019-11-03 21:24:54 49 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2019-11-03 21:24:54 49 [Note] InnoDB: Memory barrier is not used 2019-11-03 21:24:54 49 [Note] InnoDB: Compressed tables use zlib 1.2.11 2019-11-03 21:24:54 49 [Note] InnoDB: Using Linux native AIO 2019-11-03 21:24:54 49 [Note] InnoDB: Using CPU crc32 instructions 2019-11-03 21:24:54 49 [Note] InnoDB: Initializing buffer pool, size = 128.0M 2019-11-03 21:24:54 49 [Note] InnoDB: Completed initialization of buffer pool 2019-11-03 21:24:54 49 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created! 2019-11-03 21:24:54 49 [Note] InnoDB: Setting file ./ibdata1 size to 12 MB 2019-11-03 21:24:54 49 [Note] InnoDB: Database physically writes the file full: wait... 2019-11-03 21:24:54 49 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB 2019-11-03 21:24:54 49 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB 2019-11-03 21:24:55 49 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0 2019-11-03 21:24:55 49 [Warning] InnoDB: New log files created, LSN=45781 2019-11-03 21:24:55 49 [Note] InnoDB: Doublewrite buffer not found: creating new 2019-11-03 21:24:55 49 [Note] InnoDB: Doublewrite buffer created 2019-11-03 21:24:55 49 [Note] InnoDB: 128 rollback segment(s) are active. 2019-11-03 21:24:55 49 [Warning] InnoDB: Creating foreign key constraint system tables. 2019-11-03 21:24:55 49 [Note] InnoDB: Foreign key constraint system tables created 2019-11-03 21:24:55 49 [Note] InnoDB: Creating tablespace and datafile system tables. 2019-11-03 21:24:55 49 [Note] InnoDB: Tablespace and datafile system tables created. 2019-11-03 21:24:55 49 [Note] InnoDB: Waiting for purge to start 2019-11-03 21:24:55 49 [Note] InnoDB: 5.6.46 started; log sequence number 0 2019-11-03 21:24:55 49 [Note] RSA private key file not found: /var/lib/mysql//private_key.pem. Some authentication plugins will not work. 2019-11-03 21:24:55 49 [Note] RSA public key file not found: /var/lib/mysql//public_key.pem. Some authentication plugins will not work. 2019-11-03 21:24:56 49 [Note] Binlog end 2019-11-03 21:24:56 49 [Note] InnoDB: FTS optimize thread exiting. 2019-11-03 21:24:56 49 [Note] InnoDB: Starting shutdown... 2019-11-03 21:24:57 49 [Note] InnoDB: Shutdown completed; log sequence number 1625977 2019-11-03 21:24:57 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2019-11-03 21:24:57 0 [Note] Ignoring --secure-file-priv value as server is running with --bootstrap. 2019-11-03 21:24:57 0 [Note] /usr/sbin/mysqld (mysqld 5.6.46) starting as process 72 ... 2019-11-03 21:24:57 72 [Note] InnoDB: Using atomics to ref count buffer pool pages 2019-11-03 21:24:57 72 [Note] InnoDB: The InnoDB memory heap is disabled 2019-11-03 21:24:57 72 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2019-11-03 21:24:57 72 [Note] InnoDB: Memory barrier is not used 2019-11-03 21:24:57 72 [Note] InnoDB: Compressed tables use zlib 1.2.11 2019-11-03 21:24:57 72 [Note] InnoDB: Using Linux native AIO 2019-11-03 21:24:57 72 [Note] InnoDB: Using CPU crc32 instructions 2019-11-03 21:24:57 72 [Note] InnoDB: Initializing buffer pool, size = 128.0M 2019-11-03 21:24:57 72 [Note] InnoDB: Completed initialization of buffer pool 2019-11-03 21:24:57 72 [Note] InnoDB: Highest supported file format is Barracuda. 2019-11-03 21:24:57 72 [Note] InnoDB: 128 rollback segment(s) are active. 2019-11-03 21:24:57 72 [Note] InnoDB: Waiting for purge to start 2019-11-03 21:24:57 72 [Note] InnoDB: 5.6.46 started; log sequence number 1625977 2019-11-03 21:24:57 72 [Note] RSA private key file not found: /var/lib/mysql//private_key.pem. Some authentication plugins will not work. 2019-11-03 21:24:57 72 [Note] RSA public key file not found: /var/lib/mysql//public_key.pem. Some authentication plugins will not work. 2019-11-03 21:24:57 72 [Note] Binlog end 2019-11-03 21:24:57 72 [Note] InnoDB: FTS optimize thread exiting. 2019-11-03 21:24:57 72 [Note] InnoDB: Starting shutdown... functional_test.go:555: (dbg) waiting for pods with labels "app=mysql" in namespace "default" ... helpers.go:247: "mysql-5787d7b5fc-kqdrj" [90a614ba-f2d8-4318-92ae-6edd7463f14c] Running functional_test.go:555: (dbg) pods app=mysql up and healthy within 5.005878835s functional_test.go:559: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 exec mysql-5787d7b5fc-kqdrj -- mysql -ppassword -e "show databases;" --- PASS: TestFunctional/parallel/AddonsCmd (0.12s) functional_test.go:478: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 addons list functional_test.go:492: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 addons list --format "{{.AddonName}}":"{{.AddonStatus}}" functional_test.go:506: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 addons list -f "{{.AddonName}}":"{{.AddonStatus}}" functional_test.go:520: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 addons list -o json --- PASS: TestFunctional/parallel/ProfileCmd (0.05s) functional_test.go:357: (dbg) Run: out/minikube profile list functional_test.go:377: (dbg) Run: out/minikube profile list --output json --- PASS: TestFunctional/parallel/PersistentVolumeClaim (7.75s) fn_pvc.go:40: (dbg) waiting for pods with labels "integration-test=storage-provisioner" in namespace "kube-system" ... helpers.go:247: "storage-provisioner" [6c9c2d17-8119-4170-9544-5a1cbdcc68cc] Running fn_pvc.go:40: (dbg) pods integration-test=storage-provisioner up and healthy within 5.010901682s fn_pvc.go:45: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 get storageclass -o=json fn_pvc.go:65: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 apply -f testdata/pvc.yaml fn_pvc.go:71: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 get pvc testpvc -o=json fn_pvc.go:71: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 get pvc testpvc -o=json --- PASS: TestFunctional/parallel/ServiceCmd (29.28s) functional_test.go:401: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 create deployment hello-node --image=gcr.io/hello-minikube-zero-install/hello-node functional_test.go:405: (dbg) Run: kubectl --context functional-20191104T082125.872658733-18873 expose deployment hello-node --type=NodePort --port=8080 functional_test.go:410: (dbg) waiting for pods with labels "app=hello-node" in namespace "default" ... helpers.go:247: "hello-node-7676b5fb8d-nxjqs" [9b3adf91-a112-4dbc-9b19-9d8801af3b43] Pending / Ready:ContainersNotReady (containers with unready status: [hello-node]) / ContainersReady:ContainersNotReady (containers with unready status: [hello-node]) helpers.go:247: "hello-node-7676b5fb8d-nxjqs" [9b3adf91-a112-4dbc-9b19-9d8801af3b43] Running functional_test.go:410: (dbg) pods app=hello-node up and healthy within 27.004810384s functional_test.go:414: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 service list functional_test.go:414: (dbg) Done: out/minikube -p functional-20191104T082125.872658733-18873 service list: (1.640625892s) functional_test.go:423: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 service --namespace=default --https --url hello-node functional_test.go:441: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 service hello-node --url --format={{.IP}} functional_test.go:450: (dbg) Run: out/minikube -p functional-20191104T082125.872658733-18873 service hello-node --url functional_test.go:464: url: http://192.168.39.24:31849 --- PASS: TestFunctional/parallel/DashboardCmd (41.31s) functional_test.go:236: (dbg) daemon: [../../out/minikube dashboard --url -p functional-20191104T082125.872658733-18873 --alsologtostderr -v=1] functional_test.go:241: (dbg) stopping [../../out/minikube dashboard --url -p functional-20191104T082125.872658733-18873 --alsologtostderr -v=1] ... helpers.go:387: unable to kill pid 21063: os: process already finished helpers.go:167: (dbg) Run: out/minikube delete -p functional-20191104T082125.872658733-18873 helpers.go:167: (dbg) Done: out/minikube delete -p functional-20191104T082125.872658733-18873: (1.601200457s) === RUN TestAddons/parallel === RUN TestAddons/parallel/Registry === PAUSE TestAddons/parallel/Registry === RUN TestAddons/parallel/Ingress === PAUSE TestAddons/parallel/Ingress === CONT TestAddons/parallel/Registry === CONT TestAddons/parallel/Ingress 2019/11/04 08:27:50 [DEBUG] GET http://192.168.39.56:5000 --- PASS: TestAddons (192.32s) helpers.go:361: No need to wait for start slot, it is already 2019-11-04 08:24:52.30063752 +1100 AEDT m=+240.074648116 addons_test.go:46: (dbg) Run: out/minikube start -p addons-20191104T082452.300667929-18873 --wait=false --memory=2600 --alsologtostderr -v=1 --addons=ingress --addons=registry addons_test.go:46: (dbg) Done: out/minikube start -p addons-20191104T082452.300667929-18873 --wait=false --memory=2600 --alsologtostderr -v=1 --addons=ingress --addons=registry : (2m28.528135985s) --- PASS: TestAddons/parallel (0.00s) --- PASS: TestAddons/parallel/Ingress (29.68s) addons_test.go:97: (dbg) waiting for pods with labels "app.kubernetes.io/name=nginx-ingress-controller" in namespace "kube-system" ... helpers.go:247: "nginx-ingress-controller-6fc5bcc8c9-pvwsq" [03a32eb7-f4fd-43ad-89f9-73f9c9407f1b] Running / Ready:ContainersNotReady (containers with unready status: [nginx-ingress-controller]) / ContainersReady:ContainersNotReady (containers with unready status: [nginx-ingress-controller]) addons_test.go:97: (dbg) pods app.kubernetes.io/name=nginx-ingress-controller up and healthy within 5.005704761s addons_test.go:101: (dbg) Run: kubectl --context addons-20191104T082452.300667929-18873 replace --force -f testdata/nginx-ing.yaml addons_test.go:101: (dbg) Done: kubectl --context addons-20191104T082452.300667929-18873 replace --force -f testdata/nginx-ing.yaml: (2.671133592s) addons_test.go:105: (dbg) Run: kubectl --context addons-20191104T082452.300667929-18873 replace --force -f testdata/nginx-pod-svc.yaml addons_test.go:110: (dbg) waiting for pods with labels "run=nginx" in namespace "default" ... helpers.go:247: "nginx" [21d6e955-3c60-4673-b019-4b25d0af8f9d] Pending / Ready:ContainersNotReady (containers with unready status: [nginx]) / ContainersReady:ContainersNotReady (containers with unready status: [nginx]) helpers.go:247: "nginx" [21d6e955-3c60-4673-b019-4b25d0af8f9d] Running addons_test.go:110: (dbg) pods run=nginx up and healthy within 21.024403427s addons_test.go:119: (dbg) Run: out/minikube -p addons-20191104T082452.300667929-18873 ssh "curl http://127.0.0.1:80 -H 'Host: nginx.example.com'" addons_test.go:136: (dbg) Run: out/minikube -p addons-20191104T082452.300667929-18873 addons disable ingress --alsologtostderr -v=1 --- PASS: TestAddons/parallel/Registry (30.14s) addons_test.go:152: registry stabilized in 17.21522ms addons_test.go:154: (dbg) waiting for pods with labels "actual-registry=true" in namespace "kube-system" ... helpers.go:247: "registry-qw4s5" [3e6cc7cb-d88f-4a0c-9a83-29c7fbd01596] Running addons_test.go:154: (dbg) pods actual-registry=true up and healthy within 5.008192127s addons_test.go:157: (dbg) waiting for pods with labels "registry-proxy=true" in namespace "kube-system" ... helpers.go:247: "registry-proxy-dd8rs" [f07e58a3-2550-4bd1-bbbe-d0413fee18ab] Running addons_test.go:157: (dbg) pods registry-proxy=true up and healthy within 5.006662151s addons_test.go:162: (dbg) Run: kubectl --context addons-20191104T082452.300667929-18873 delete po -l run=registry-test --now addons_test.go:167: (dbg) Run: kubectl --context addons-20191104T082452.300667929-18873 run --rm registry-test --restart=Never --image=busybox -it -- sh -c "wget --spider -S http://registry.kube-system.svc.cluster.local" addons_test.go:167: (dbg) Done: kubectl --context addons-20191104T082452.300667929-18873 run --rm registry-test --restart=Never --image=busybox -it -- sh -c "wget --spider -S http://registry.kube-system.svc.cluster.local": (19.592473452s) addons_test.go:177: (dbg) Run: out/minikube -p addons-20191104T082452.300667929-18873 ip addons_test.go:206: (dbg) Run: out/minikube -p addons-20191104T082452.300667929-18873 addons disable registry --alsologtostderr -v=1 addons_test.go:70: (dbg) Run: out/minikube stop -p addons-20191104T082452.300667929-18873 addons_test.go:70: (dbg) Done: out/minikube stop -p addons-20191104T082452.300667929-18873: (13.233220482s) addons_test.go:74: (dbg) Run: out/minikube addons enable dashboard -p addons-20191104T082452.300667929-18873 addons_test.go:78: (dbg) Run: out/minikube addons disable dashboard -p addons-20191104T082452.300667929-18873 helpers.go:167: (dbg) Run: out/minikube delete -p addons-20191104T082452.300667929-18873 --- PASS: TestDockerFlags (235.66s) helpers.go:358: Waiting for start slot at 2019-11-04 08:25:52.300626185 +1100 AEDT m=+300.074636780 (sleeping 59.999921632s) ... docker_test.go:42: (dbg) Run: out/minikube start -p docker-flags-20191104T082552.300971973-18873 --wait=false --docker-env=FOO=BAR --docker-env=BAZ=BAT --docker-opt=debug --docker-opt=icc=true --alsologtostderr -v=5 docker_test.go:42: (dbg) Done: out/minikube start -p docker-flags-20191104T082552.300971973-18873 --wait=false --docker-env=FOO=BAR --docker-env=BAZ=BAT --docker-opt=debug --docker-opt=icc=true --alsologtostderr -v=5 : (2m54.076176539s) docker_test.go:47: (dbg) Run: out/minikube -p docker-flags-20191104T082552.300971973-18873 ssh "systemctl show docker --property=Environment --no-pager" docker_test.go:58: (dbg) Run: out/minikube -p docker-flags-20191104T082552.300971973-18873 ssh "systemctl show docker --property=ExecStart --no-pager" helpers.go:167: (dbg) Run: out/minikube delete -p docker-flags-20191104T082552.300971973-18873 helpers.go:167: (dbg) Done: out/minikube delete -p docker-flags-20191104T082552.300971973-18873: (1.132863792s) --- PASS: TestVersionUpgrade (369.17s) helpers.go:358: Waiting for start slot at 2019-11-04 08:25:22.300626185 +1100 AEDT m=+270.074636780 (sleeping 29.999935731s) ... version_upgrade_test.go:70: (dbg) Run: /tmp/minikube-release.878849777.exe start -p vupgrade-20191104T082522.300800849-18873 --kubernetes-version=v1.11.10 --alsologtostderr -v=1 version_upgrade_test.go:70: (dbg) Done: /tmp/minikube-release.878849777.exe start -p vupgrade-20191104T082522.300800849-18873 --kubernetes-version=v1.11.10 --alsologtostderr -v=1 : (2m58.197200416s) version_upgrade_test.go:79: (dbg) Run: /tmp/minikube-release.878849777.exe stop -p vupgrade-20191104T082522.300800849-18873 version_upgrade_test.go:79: (dbg) Done: /tmp/minikube-release.878849777.exe stop -p vupgrade-20191104T082522.300800849-18873: (14.155612976s) version_upgrade_test.go:84: (dbg) Run: /tmp/minikube-release.878849777.exe -p vupgrade-20191104T082522.300800849-18873 status --format={{.Host}} version_upgrade_test.go:84: (dbg) Non-zero exit: /tmp/minikube-release.878849777.exe -p vupgrade-20191104T082522.300800849-18873 status --format={{.Host}}: exit status 1 (68.698765ms) -- stdout -- Stopped -- /stdout -- version_upgrade_test.go:86: status error: exit status 1 (may be ok) helpers.go:361: No need to wait for start slot, it is already 2019-11-04 08:28:37.164720757 +1100 AEDT m=+464.938731345 version_upgrade_test.go:95: (dbg) Run: out/minikube start -p vupgrade-20191104T082522.300800849-18873 --kubernetes-version=v1.16.2 --alsologtostderr -v=1 version_upgrade_test.go:95: (dbg) Done: out/minikube start -p vupgrade-20191104T082522.300800849-18873 --kubernetes-version=v1.16.2 --alsologtostderr -v=1 : (2m23.324335645s) helpers.go:167: (dbg) Run: out/minikube delete -p vupgrade-20191104T082522.300800849-18873 --- PASS: TestStartStop (626.25s) --- PASS: TestStartStop/group (0.00s) --- PASS: TestStartStop/group/docker (416.69s) helpers.go:358: Waiting for start slot at 2019-11-04 08:26:22.300626185 +1100 AEDT m=+330.074636780 (sleeping 1m29.999762906s) ... start_stop_delete_test.go:91: (dbg) Run: out/minikube start -p docker-20191104T082622.300761702-18873 --alsologtostderr -v=3 --wait=true --cache-images=false --kubernetes-version=v1.11.10 --kvm-network=default --kvm-qemu-uri=qemu:///system --disable-driver-mounts --keep-context=false --container-runtime=docker start_stop_delete_test.go:91: (dbg) Done: out/minikube start -p docker-20191104T082622.300761702-18873 --alsologtostderr -v=3 --wait=true --cache-images=false --kubernetes-version=v1.11.10 --kvm-network=default --kvm-qemu-uri=qemu:///system --disable-driver-mounts --keep-context=false --container-runtime=docker : (3m9.827465706s) start_stop_delete_test.go:102: (dbg) Run: kubectl --context docker-20191104T082622.300761702-18873 create -f testdata/busybox.yaml start_stop_delete_test.go:102: (dbg) Done: kubectl --context docker-20191104T082622.300761702-18873 create -f testdata/busybox.yaml: (1.045195614s) start_stop_delete_test.go:107: (dbg) waiting for pods with labels "integration-test=busybox" in namespace "default" ... helpers.go:247: "busybox" [06dd0c10-fe81-11e9-a894-5c5fdd3720f5] Pending / Ready:ContainersNotReady (containers with unready status: [busybox]) / ContainersReady:ContainersNotReady (containers with unready status: [busybox]) helpers.go:247: "busybox" [06dd0c10-fe81-11e9-a894-5c5fdd3720f5] Running start_stop_delete_test.go:107: (dbg) pods integration-test=busybox up and healthy within 16.06885973s start_stop_delete_test.go:113: (dbg) Run: kubectl --context docker-20191104T082622.300761702-18873 exec busybox -- /bin/sh -c "ulimit -n" start_stop_delete_test.go:130: (dbg) Run: out/minikube stop -p docker-20191104T082622.300761702-18873 --alsologtostderr -v=3 start_stop_delete_test.go:130: (dbg) Done: out/minikube stop -p docker-20191104T082622.300761702-18873 --alsologtostderr -v=3: (17.353839074s) start_stop_delete_test.go:135: (dbg) Run: out/minikube status --format={{.Host}} -p docker-20191104T082622.300761702-18873 start_stop_delete_test.go:135: (dbg) Non-zero exit: out/minikube status --format={{.Host}} -p docker-20191104T082622.300761702-18873: exit status 1 (37.663869ms) -- stdout -- Stopped -- /stdout -- start_stop_delete_test.go:135: status error: exit status 1 (may be ok) helpers.go:361: No need to wait for start slot, it is already 2019-11-04 08:30:07.029124735 +1100 AEDT m=+554.803135321 start_stop_delete_test.go:141: (dbg) Run: out/minikube start -p docker-20191104T082622.300761702-18873 --alsologtostderr -v=3 --wait=true --cache-images=false --kubernetes-version=v1.11.10 --kvm-network=default --kvm-qemu-uri=qemu:///system --disable-driver-mounts --keep-context=false --container-runtime=docker start_stop_delete_test.go:141: (dbg) Done: out/minikube start -p docker-20191104T082622.300761702-18873 --alsologtostderr -v=3 --wait=true --cache-images=false --kubernetes-version=v1.11.10 --kvm-network=default --kvm-qemu-uri=qemu:///system --disable-driver-mounts --keep-context=false --container-runtime=docker : (1m35.29120763s) start_stop_delete_test.go:149: (dbg) waiting for pods with labels "integration-test=busybox" in namespace "default" ... helpers.go:247: "busybox" [06dd0c10-fe81-11e9-a894-5c5fdd3720f5] Running start_stop_delete_test.go:149: (dbg) pods integration-test=busybox up and healthy within 5.642024689s start_stop_delete_test.go:153: (dbg) Run: out/minikube status --format={{.Host}} -p docker-20191104T082622.300761702-18873 helpers.go:167: (dbg) Run: out/minikube delete -p docker-20191104T082622.300761702-18873 --- PASS: TestStartStop/group/cni (467.93s) helpers.go:358: Waiting for start slot at 2019-11-04 08:27:52.300626185 +1100 AEDT m=+420.074636780 (sleeping 2m59.999736017s) ... start_stop_delete_test.go:91: (dbg) Run: out/minikube start -p cni-20191104T082752.300771556-18873 --alsologtostderr -v=3 --wait=true --feature-gates ServerSideApply=true --network-plugin=cni --extra-config=kubelet.network-plugin=cni --extra-config=kubeadm.pod-network-cidr=192.168.111.111/16 --kubernetes-version=v1.16.2 start_stop_delete_test.go:91: (dbg) Done: out/minikube start -p cni-20191104T082752.300771556-18873 --alsologtostderr -v=3 --wait=true --feature-gates ServerSideApply=true --network-plugin=cni --extra-config=kubelet.network-plugin=cni --extra-config=kubeadm.pod-network-cidr=192.168.111.111/16 --kubernetes-version=v1.16.2 : (3m50.111617403s) start_stop_delete_test.go:99: WARNING: cni mode requires additional setup before pods can schedule :( start_stop_delete_test.go:130: (dbg) Run: out/minikube stop -p cni-20191104T082752.300771556-18873 --alsologtostderr -v=3 start_stop_delete_test.go:130: (dbg) Done: out/minikube stop -p cni-20191104T082752.300771556-18873 --alsologtostderr -v=3: (13.361886938s) start_stop_delete_test.go:135: (dbg) Run: out/minikube status --format={{.Host}} -p cni-20191104T082752.300771556-18873 start_stop_delete_test.go:135: (dbg) Non-zero exit: out/minikube status --format={{.Host}} -p cni-20191104T082752.300771556-18873: exit status 1 (40.269985ms) -- stdout -- Stopped -- /stdout -- start_stop_delete_test.go:135: status error: exit status 1 (may be ok) helpers.go:361: No need to wait for start slot, it is already 2019-11-04 08:31:55.814766655 +1100 AEDT m=+663.588777252 start_stop_delete_test.go:141: (dbg) Run: out/minikube start -p cni-20191104T082752.300771556-18873 --alsologtostderr -v=3 --wait=true --feature-gates ServerSideApply=true --network-plugin=cni --extra-config=kubelet.network-plugin=cni --extra-config=kubeadm.pod-network-cidr=192.168.111.111/16 --kubernetes-version=v1.16.2 start_stop_delete_test.go:141: (dbg) Done: out/minikube start -p cni-20191104T082752.300771556-18873 --alsologtostderr -v=3 --wait=true --feature-gates ServerSideApply=true --network-plugin=cni --extra-config=kubelet.network-plugin=cni --extra-config=kubeadm.pod-network-cidr=192.168.111.111/16 --kubernetes-version=v1.16.2 : (43.328528439s) start_stop_delete_test.go:148: WARNING: cni mode requires additional setup before pods can schedule :( start_stop_delete_test.go:153: (dbg) Run: out/minikube status --format={{.Host}} -p cni-20191104T082752.300771556-18873 helpers.go:167: (dbg) Run: out/minikube delete -p cni-20191104T082752.300771556-18873 --- PASS: TestStartStop/group/containerd (555.16s) helpers.go:358: Waiting for start slot at 2019-11-04 08:26:52.300626185 +1100 AEDT m=+360.074636780 (sleeping 1m59.999750306s) ... start_stop_delete_test.go:91: (dbg) Run: out/minikube start -p containerd-20191104T082652.300780979-18873 --alsologtostderr -v=3 --wait=true --container-runtime=containerd --docker-opt containerd=/var/run/containerd/containerd.sock --apiserver-port=8444 start_stop_delete_test.go:91: (dbg) Done: out/minikube start -p containerd-20191104T082652.300780979-18873 --alsologtostderr -v=3 --wait=true --container-runtime=containerd --docker-opt containerd=/var/run/containerd/containerd.sock --apiserver-port=8444 : (4m29.732924894s) start_stop_delete_test.go:102: (dbg) Run: kubectl --context containerd-20191104T082652.300780979-18873 create -f testdata/busybox.yaml start_stop_delete_test.go:102: (dbg) Done: kubectl --context containerd-20191104T082652.300780979-18873 create -f testdata/busybox.yaml: (3.022589629s) start_stop_delete_test.go:107: (dbg) waiting for pods with labels "integration-test=busybox" in namespace "default" ... helpers.go:247: "busybox" [90846118-a891-4edd-86a1-4df14dbdacdd] Pending helpers.go:247: "busybox" [90846118-a891-4edd-86a1-4df14dbdacdd] Pending / Ready:ContainersNotReady (containers with unready status: [busybox]) / ContainersReady:ContainersNotReady (containers with unready status: [busybox]) helpers.go:247: "busybox" [90846118-a891-4edd-86a1-4df14dbdacdd] Running start_stop_delete_test.go:107: (dbg) pods integration-test=busybox up and healthy within 11.883410366s start_stop_delete_test.go:113: (dbg) Run: kubectl --context containerd-20191104T082652.300780979-18873 exec busybox -- /bin/sh -c "ulimit -n" start_stop_delete_test.go:130: (dbg) Run: out/minikube stop -p containerd-20191104T082652.300780979-18873 --alsologtostderr -v=3 start_stop_delete_test.go:130: (dbg) Done: out/minikube stop -p containerd-20191104T082652.300780979-18873 --alsologtostderr -v=3: (1m31.837876123s) start_stop_delete_test.go:135: (dbg) Run: out/minikube status --format={{.Host}} -p containerd-20191104T082652.300780979-18873 start_stop_delete_test.go:135: (dbg) Non-zero exit: out/minikube status --format={{.Host}} -p containerd-20191104T082652.300780979-18873: exit status 1 (35.925354ms) -- stdout -- Stopped -- /stdout -- start_stop_delete_test.go:135: status error: exit status 1 (may be ok) helpers.go:361: No need to wait for start slot, it is already 2019-11-04 08:33:09.026967426 +1100 AEDT m=+736.800978015 start_stop_delete_test.go:141: (dbg) Run: out/minikube start -p containerd-20191104T082652.300780979-18873 --alsologtostderr -v=3 --wait=true --container-runtime=containerd --docker-opt containerd=/var/run/containerd/containerd.sock --apiserver-port=8444 start_stop_delete_test.go:141: (dbg) Done: out/minikube start -p containerd-20191104T082652.300780979-18873 --alsologtostderr -v=3 --wait=true --container-runtime=containerd --docker-opt containerd=/var/run/containerd/containerd.sock --apiserver-port=8444 : (52.484285038s) start_stop_delete_test.go:149: (dbg) waiting for pods with labels "integration-test=busybox" in namespace "default" ... helpers.go:247: "busybox" [90846118-a891-4edd-86a1-4df14dbdacdd] Running / Ready:ContainersNotReady (containers with unready status: [busybox]) / ContainersReady:ContainersNotReady (containers with unready status: [busybox]) helpers.go:247: "busybox" [90846118-a891-4edd-86a1-4df14dbdacdd] Running start_stop_delete_test.go:149: (dbg) pods integration-test=busybox up and healthy within 5.008644281s start_stop_delete_test.go:153: (dbg) Run: out/minikube status --format={{.Host}} -p containerd-20191104T082652.300780979-18873 helpers.go:167: (dbg) Run: out/minikube delete -p containerd-20191104T082652.300780979-18873 --- PASS: TestStartStop/group/crio (626.25s) helpers.go:358: Waiting for start slot at 2019-11-04 08:27:22.300626185 +1100 AEDT m=+390.074636780 (sleeping 2m29.999745542s) ... start_stop_delete_test.go:91: (dbg) Run: out/minikube start -p crio-20191104T082722.304206154-18873 --alsologtostderr -v=3 --wait=true --container-runtime=crio --disable-driver-mounts --extra-config=kubeadm.ignore-preflight-errors=SystemVerification start_stop_delete_test.go:91: (dbg) Done: out/minikube start -p crio-20191104T082722.304206154-18873 --alsologtostderr -v=3 --wait=true --container-runtime=crio --disable-driver-mounts --extra-config=kubeadm.ignore-preflight-errors=SystemVerification : (4m52.989940404s) start_stop_delete_test.go:102: (dbg) Run: kubectl --context crio-20191104T082722.304206154-18873 create -f testdata/busybox.yaml start_stop_delete_test.go:107: (dbg) waiting for pods with labels "integration-test=busybox" in namespace "default" ... helpers.go:247: "busybox" [2660e105-871f-4b5e-8e06-306ee3ed6648] Pending helpers.go:247: "busybox" [2660e105-871f-4b5e-8e06-306ee3ed6648] Pending / Ready:ContainersNotReady (containers with unready status: [busybox]) / ContainersReady:ContainersNotReady (containers with unready status: [busybox]) helpers.go:247: "busybox" [2660e105-871f-4b5e-8e06-306ee3ed6648] Running start_stop_delete_test.go:107: (dbg) pods integration-test=busybox up and healthy within 8.510315758s start_stop_delete_test.go:113: (dbg) Run: kubectl --context crio-20191104T082722.304206154-18873 exec busybox -- /bin/sh -c "ulimit -n" start_stop_delete_test.go:130: (dbg) Run: out/minikube stop -p crio-20191104T082722.304206154-18873 --alsologtostderr -v=3 start_stop_delete_test.go:130: (dbg) Done: out/minikube stop -p crio-20191104T082722.304206154-18873 --alsologtostderr -v=3: (1m32.087370333s) start_stop_delete_test.go:135: (dbg) Run: out/minikube status --format={{.Host}} -p crio-20191104T082722.304206154-18873 start_stop_delete_test.go:135: (dbg) Non-zero exit: out/minikube status --format={{.Host}} -p crio-20191104T082722.304206154-18873: exit status 1 (35.519744ms) -- stdout -- Stopped -- /stdout -- start_stop_delete_test.go:135: status error: exit status 1 (may be ok) helpers.go:361: No need to wait for start slot, it is already 2019-11-04 08:33:56.977436358 +1100 AEDT m=+784.751446950 start_stop_delete_test.go:141: (dbg) Run: out/minikube start -p crio-20191104T082722.304206154-18873 --alsologtostderr -v=3 --wait=true --container-runtime=crio --disable-driver-mounts --extra-config=kubeadm.ignore-preflight-errors=SystemVerification start_stop_delete_test.go:141: (dbg) Done: out/minikube start -p crio-20191104T082722.304206154-18873 --alsologtostderr -v=3 --wait=true --container-runtime=crio --disable-driver-mounts --extra-config=kubeadm.ignore-preflight-errors=SystemVerification : (1m15.390161848s) start_stop_delete_test.go:149: (dbg) waiting for pods with labels "integration-test=busybox" in namespace "default" ... helpers.go:247: "busybox" [2660e105-871f-4b5e-8e06-306ee3ed6648] Running start_stop_delete_test.go:149: (dbg) pods integration-test=busybox up and healthy within 5.011162349s start_stop_delete_test.go:153: (dbg) Run: out/minikube status --format={{.Host}} -p crio-20191104T082722.304206154-18873 helpers.go:167: (dbg) Run: out/minikube delete -p crio-20191104T082722.304206154-18873 PASS ok k8s.io/minikube/test/integration 866.327s