Make --wait=false non-blocking, --wait=true blocks on system pods #5894

tstromberg · 2019-11-12T21:45:38Z

So, it turns out that a late comment I made in #5757 had an impactful performance regression:

Do you mind confirming that kubectl get po -A returns non-zero content with this PR?

minikube start && kubectl get po -A should at least return the apiserver.

It turns out that waiting for pod lists to return data is effectively the same as waiting for etcd to come up. This PR changes --wait=false to it's original behavior (no wait!), but keeps the default behavior of waiting for the apiserver to return results.

To simplify the code path down to 2 behaviors, we no longer have specific waits for each pod, but instead use the current behavior of waiting for the apiserver pod results as a proxy for health.

--wait=false behavior at master:

time ./out/minikube start --wait=false && kubectl get po -A

Took 154 seconds, but returned all of the expected data (note the etcd state):

⌛  Waiting for: apiserver
🏄  Done! kubectl is now configured to use "minikube"
      154.74 real         1.56 user         2.72 sys

NAMESPACE     NAME                                        READY   STATUS    RESTARTS   AGE
kube-system   coredns-5644d7b6d9-dk9jp                    1/1     Running   0          76s
kube-system   coredns-5644d7b6d9-zjmdv                    1/1     Running   0          77s
kube-system   etcd-minikube                               1/1     Running   0          15s
kube-system   kube-addon-manager-minikube                 1/1     Running   0          86s
kube-system   kube-apiserver-minikube                     0/1     Pending   0          1s
kube-system   kube-controller-manager-minikube            1/1     Running   0          11s
kube-system   kube-proxy-r89gn                            1/1     Running   0          77s
kube-system   nginx-ingress-controller-6fc5bcc8c9-w6gjq   1/1     Running   0          75s
kube-system   storage-provisioner                         1/1     Running   0          75s

Duration:

--wait=false behavior with this PR:

time ./out/minikube start --wait=false && kubectl get po -A

Took 81 seconds, but everything is pending, and apiserver does not yet appear in pod results:

🐳  Preparing Kubernetes v1.16.2 on Docker '18.09.9' ...
🚜  Pulling images ...
🚀  Launching Kubernetes ... 
🏄  Done! kubectl is now configured to use "minikube"
       81.88 real         1.33 user         2.44 sys

NAMESPACE     NAME                          READY   STATUS    RESTARTS   AGE
kube-system   coredns-5644d7b6d9-6m9s2      0/1     Pending   0          0s
kube-system   coredns-5644d7b6d9-h6fmz      0/1     Pending   0          0s
kube-system   kube-addon-manager-minikube   1/1     Running   0          10s
kube-system   kube-proxy-9vsbj              0/1     Pending   0          0s

--wait=true behavior with this PR:

time ./out/minikube start --wait=true && kubectl get po -A

Took 82 seconds, but apiserver does not yet appear in pod results:

🚀  Launching Kubernetes ... 
⌛  Waiting for cluster to come online ...
🏄  Done! kubectl is now configured to use "minikube"
       82.81 real         1.40 user         2.62 sys
NAMESPACE     NAME                                        READY   STATUS              RESTARTS   AGE
kube-system   coredns-5644d7b6d9-gjkcp                    0/1     Running             0          3s
kube-system   coredns-5644d7b6d9-mgcfl                    0/1     Running             0          3s
kube-system   kube-addon-manager-minikube                 1/1     Running             0          13s
kube-system   kube-proxy-q7r5p                            1/1     Running             0          3s
kube-system   nginx-ingress-controller-6fc5bcc8c9-7txhq   0/1     ContainerCreating   0          1s
kube-system   storage-provisioner                         0/1     ContainerCreating   0          1s

k8s-ci-robot · 2019-11-12T21:46:22Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: tstromberg

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~OWNERS~~ [tstromberg]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

tstromberg · 2019-11-12T21:47:22Z

/ok-to-test

minikube-bot · 2019-11-12T22:32:32Z

All Times minikube: [ 176.582281 180.449595 187.314829]
All Times Minikube (PR 5894): [ 114.013129 113.443388 116.497478]

Average minikube: 181.448902
Average Minikube (PR 5894): 114.651332

Averages Time Per Log

+------------------------+-----------+--------------------+
|          LOG           | MINIKUBE  | MINIKUBE (PR 5894) |
+------------------------+-----------+--------------------+
| minikube v             |  0.309964 |           0.301271 |
| Creating kvm2          | 39.609788 |          38.073822 |
| Preparing Kubernetes   | 53.682617 |          52.974591 |
| Pulling images         |  2.857304 |           2.969220 |
| Launching Kubernetes   | 20.710391 |          20.254508 |
| Waiting for: apiserver | 64.234283 |                    |
+------------------------+-----------+--------------------+

codecov-io · 2019-11-12T22:40:36Z

Codecov Report

Merging #5894 into master will decrease coverage by 0.13%.
The diff coverage is 1.36%.

@@            Coverage Diff             @@
##           master    #5894      +/-   ##
==========================================
- Coverage   36.44%   36.31%   -0.14%     
==========================================
  Files         110      110              
  Lines        8161     8160       -1     
==========================================
- Hits         2974     2963      -11     
- Misses       4796     4806      +10     
  Partials      391      391

Impacted Files	Coverage Δ
pkg/minikube/out/style.go	`91.66% <ø> (ø)`	⬆️
pkg/minikube/bootstrapper/bootstrapper.go	`0% <ø> (ø)`	⬆️
pkg/minikube/bootstrapper/kubeadm/kubeadm.go	`18.83% <0%> (-2.71%)`	⬇️
cmd/minikube/cmd/start.go	`19.53% <25%> (+0.11%)`	⬆️

priyawadhwa · 2019-11-12T23:40:23Z

So there's a missing time in the table for Waiting for: apiserver because the log was changed to Waiting for cluster to come online in this PR. From the logs, it looks like it took 0.032274, 0.034415, and 0.038305 seconds for that to run.

Nice speedup!

priyawadhwa

LGTM. Had one question.

pkg/minikube/bootstrapper/kubeadm/kubeadm.go

minikube-bot · 2019-11-13T04:32:41Z

All Times minikube: [ 177.172030 191.691567 181.014751]
All Times Minikube (PR 5894): [ 113.219124 114.814838 113.232620]

Average minikube: 183.292783
Average Minikube (PR 5894): 113.755527

Averages Time Per Log

+------------------------+-----------+--------------------+
|          LOG           | MINIKUBE  | MINIKUBE (PR 5894) |
+------------------------+-----------+--------------------+
| minikube v             |  0.321641 |           0.307606 |
| Creating kvm2          | 39.322818 |          38.065466 |
| Preparing Kubernetes   | 52.878781 |          52.427285 |
| Pulling images         |  2.884734 |           2.893177 |
| Launching Kubernetes   | 20.275210 |          19.973949 |
| Waiting for: apiserver | 67.564563 |                    |
+------------------------+-----------+--------------------+

minikube-bot · 2019-11-13T05:39:04Z

All Times minikube: [ 179.847896 183.698483 196.145768]
All Times Minikube (PR 5894): [ 121.587710 123.361656 124.877984]

Average minikube: 186.564049
Average Minikube (PR 5894): 123.275783

Averages Time Per Log

+------------------------+-----------+--------------------+
|          LOG           | MINIKUBE  | MINIKUBE (PR 5894) |
+------------------------+-----------+--------------------+
| minikube v             |  0.318460 |           0.300037 |
| Creating kvm2          | 39.343187 |          38.293692 |
| Preparing Kubernetes   | 52.004184 |          52.453563 |
| Pulling images         |  2.902987 |           3.187990 |
| Launching Kubernetes   | 19.882826 |          20.583061 |
| Waiting for: apiserver | 72.067159 |                    |
+------------------------+-----------+--------------------+

minikube-bot · 2019-11-13T06:04:35Z

All Times minikube: [ 173.835848 176.293193 181.162661]
All Times Minikube (PR 5894): [ 122.971403 129.877476 128.462233]

Average Minikube (PR 5894): 127.103704
Average minikube: 177.097234

Averages Time Per Log

+------------------------+-----------+--------------------+
|          LOG           | MINIKUBE  | MINIKUBE (PR 5894) |
+------------------------+-----------+--------------------+
| minikube v             |  0.308888 |           0.332420 |
| Creating kvm2          | 40.241700 |          40.621187 |
| Preparing Kubernetes   | 54.714268 |          55.200595 |
| Pulling images         |  2.464435 |           2.795977 |
| Launching Kubernetes   | 19.255409 |          20.216916 |
| Waiting for: apiserver | 60.067640 |                    |
+------------------------+-----------+--------------------+

minikube-bot · 2019-11-13T07:00:41Z

All Times minikube: [ 189.252996 170.981930 194.983028]
All Times Minikube (PR 5894): [ 119.691746 122.912079 122.593160]

Average minikube: 185.072651
Average Minikube (PR 5894): 121.732328

Averages Time Per Log

+------------------------+-----------+--------------------+
|          LOG           | MINIKUBE  | MINIKUBE (PR 5894) |
+------------------------+-----------+--------------------+
| minikube v             |  0.296769 |           0.299267 |
| Creating kvm2          | 38.253645 |          37.995389 |
| Preparing Kubernetes   | 53.898132 |          53.131636 |
| Pulling images         |  6.283785 |           2.840813 |
| Launching Kubernetes   | 19.238306 |          20.177843 |
| Waiting for: apiserver | 67.057906 |                    |
+------------------------+-----------+--------------------+

minikube-bot · 2019-11-13T15:03:30Z

All Times minikube: [ 178.978900 181.260265 178.118128]
All Times Minikube (PR 5894): [ 123.231990 126.558328 122.947210]

Average minikube: 179.452431
Average Minikube (PR 5894): 124.245843

Averages Time Per Log

+------------------------+-----------+--------------------+
|          LOG           | MINIKUBE  | MINIKUBE (PR 5894) |
+------------------------+-----------+--------------------+
| minikube v             |  0.319556 |           0.300725 |
| Creating kvm2          | 40.369227 |          38.934727 |
| Preparing Kubernetes   | 51.486378 |          53.465086 |
| Pulling images         |  2.842133 |           2.856922 |
| Launching Kubernetes   | 19.155007 |          20.401876 |
| Waiting for: apiserver | 65.234795 |                    |
+------------------------+-----------+--------------------+

Make --wait=false wait for nothing again, change default to --wait=true

dc3a50e

tstromberg requested review from medyagh and priyawadhwa November 12, 2019 21:45

k8s-ci-robot added cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. size/L Denotes a PR that changes 100-499 lines, ignoring generated files. labels Nov 12, 2019

k8s-ci-robot requested a review from blueelvis November 12, 2019 21:46

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Nov 12, 2019

tstromberg changed the title ~~Make --wait=false wait for nothing again, change default to --wait=true~~ --wait=false should block on nothing, revert default --wait to true Nov 12, 2019

k8s-ci-robot added the ok-to-test Indicates a non-member PR verified by an org member that is safe to test. label Nov 12, 2019

medyagh approved these changes Nov 12, 2019

View reviewed changes

tstromberg changed the title ~~--wait=false should block on nothing, revert default --wait to true~~ Make --wait=false non-blocking, --wait=true blocks on system pods Nov 12, 2019

Wait for any kube-system pod rather than apiserver (much faster)

e142319

kubernetes deleted a comment from minikube-bot Nov 12, 2019

Remove unused tests

2128326

kubernetes deleted a comment from minikube-bot Nov 12, 2019

tstromberg added 2 commits November 12, 2019 14:22

Clarify help text for --wait

55a7002

Clarify help text for --wait, take kubernetes#2

4ae9392

priyawadhwa approved these changes Nov 13, 2019

View reviewed changes

pkg/minikube/bootstrapper/kubeadm/kubeadm.go Outdated Show resolved Hide resolved

Set kubectl context in validateKubectlGetPods

f5736fd

tstromberg added 3 commits November 12, 2019 21:14

Split WaitForCluster up into smaller functions, be more conservative

7e5ab04

Clarify restart code, remove duplicate health check

2411895

Add stderr checking to validateKubectlGetPods

6ba0593

Lint

506cd94

KubectlGetPods now requires --wait=true

00c33d0

Double pod test waits

e338ac0

tstromberg merged commit d44aa4c into kubernetes:master Nov 13, 2019

This was referenced Nov 15, 2019

Remove noisy warning message while apiserver is booting up #5918

Merged

Update changelog for v1.6.0-beta.0 release #5929

Merged

priyawadhwa mentioned this pull request Dec 16, 2019

make WaitCluster smarter. #5125

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Make --wait=false non-blocking, --wait=true blocks on system pods #5894

Make --wait=false non-blocking, --wait=true blocks on system pods #5894

tstromberg commented Nov 12, 2019 •

edited

Loading

k8s-ci-robot commented Nov 12, 2019

tstromberg commented Nov 12, 2019

minikube-bot commented Nov 12, 2019

codecov-io commented Nov 12, 2019 •

edited

Loading

priyawadhwa commented Nov 12, 2019 •

edited

Loading

priyawadhwa left a comment

minikube-bot commented Nov 13, 2019

minikube-bot commented Nov 13, 2019

minikube-bot commented Nov 13, 2019

minikube-bot commented Nov 13, 2019

minikube-bot commented Nov 13, 2019

Make --wait=false non-blocking, --wait=true blocks on system pods #5894

Make --wait=false non-blocking, --wait=true blocks on system pods #5894

Conversation

tstromberg commented Nov 12, 2019 • edited Loading

--wait=false behavior at master:

--wait=false behavior with this PR:

--wait=true behavior with this PR:

k8s-ci-robot commented Nov 12, 2019

tstromberg commented Nov 12, 2019

minikube-bot commented Nov 12, 2019

codecov-io commented Nov 12, 2019 • edited Loading

Codecov Report

priyawadhwa commented Nov 12, 2019 • edited Loading

priyawadhwa left a comment

Choose a reason for hiding this comment

minikube-bot commented Nov 13, 2019

minikube-bot commented Nov 13, 2019

minikube-bot commented Nov 13, 2019

minikube-bot commented Nov 13, 2019

minikube-bot commented Nov 13, 2019

tstromberg commented Nov 12, 2019 •

edited

Loading

codecov-io commented Nov 12, 2019 •

edited

Loading

priyawadhwa commented Nov 12, 2019 •

edited

Loading