Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Added WaitGroups to prevent stderr/stdout from being empty in error logs #10694

Merged
merged 2 commits into from
Mar 3, 2021

Conversation

spowelljr
Copy link
Member

Closes #10570

Issue was sometimes error logs were being written out, but stderr was empty. The cause was that there were no WaitGroups to ensure that the logs had finished piping before outputting the error, sometimes resulting with no or partial stderr logs. This fix implements WaitGroups to ensure that the logs have finished piping before outputting the error.

@k8s-ci-robot k8s-ci-robot added the cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. label Mar 2, 2021
@k8s-ci-robot k8s-ci-robot added the size/M Denotes a PR that changes 30-99 lines, ignoring generated files. label Mar 2, 2021
@spowelljr spowelljr changed the title Added WaitGroups to prevent stderr/stdout to from being truncated Added WaitGroups to prevent stderr/stdout from being empty on error output Mar 2, 2021
@spowelljr spowelljr changed the title Added WaitGroups to prevent stderr/stdout from being empty on error output Added WaitGroups to prevent stderr/stdout from being empty in error logs Mar 2, 2021
@medyagh
Copy link
Member

medyagh commented Mar 2, 2021

/ok-to-test

@k8s-ci-robot k8s-ci-robot added the ok-to-test Indicates a non-member PR verified by an org member that is safe to test. label Mar 2, 2021
@kubernetes kubernetes deleted a comment from minikube-pr-bot Mar 2, 2021
@minikube-bot
Copy link
Collaborator

Can one of the admins verify this patch?

@minikube-pr-bot
Copy link

kvm2 Driver
Times for minikube: 70.0s 71.8s 70.0s
Average time for minikube: 70.6s

Times for Minikube (PR 10694): 69.9s 68.5s 68.8s
Average time for Minikube (PR 10694): 69.1s

Averages Time Per Log

+--------------------------------------------+----------+---------------------+
|                    LOG                     | MINIKUBE | MINIKUBE (PR 10694) |
+--------------------------------------------+----------+---------------------+
| * minikube v1.18.0 on Debian               | 0.0s     | 0.0s                |
| 9.11 (kvm/amd64)                           |          |                     |
| * Using the kvm2 driver based              | 0.0s     | 0.0s                |
| on user configuration                      |          |                     |
| * Starting control plane node              | 0.0s     | 0.0s                |
| minikube in cluster minikube               |          |                     |
| * Creating kvm2 VM (CPUs=2,                | 43.5s    | 42.1s               |
| Memory=3700MB, Disk=20000MB)               |          |                     |
| ...                                        |          |                     |
| * Preparing Kubernetes v1.20.2             | 9.9s     | 9.4s                |
| on Docker 20.10.3 ...                      |          |                     |
|   - Generating certificates                | 3.1s     | 2.5s                |
| and keys ...                               |          |                     |
|   - Booting up control plane               | 10.6s    | 11.1s               |
| ...                                        |          |                     |
|   - Configuring RBAC rules ...             | 1.3s     | 1.2s                |
| * Verifying Kubernetes                     | 0.1s     | 0.1s                |
| components...                              |          |                     |
|   - Using image                            | 1.7s     | 1.7s                |
| gcr.io/k8s-minikube/storage-provisioner:v4 |          |                     |
| * Enabled addons:                          | 0.5s     | 0.9s                |
| storage-provisioner,                       |          |                     |
| default-storageclass                       |          |                     |
| * Done! kubectl is now                     | 0.0s     | 0.0s                |
| configured to use "minikube"               |          |                     |
| cluster and "default"                      |          |                     |
| namespace by default                       |          |                     |
+--------------------------------------------+----------+---------------------+

docker Driver
Times for minikube: 27.6s 27.2s 26.9s
Average time for minikube: 27.3s

Times for Minikube (PR 10694): 27.1s 27.0s 27.2s
Average time for Minikube (PR 10694): 27.1s

Averages Time Per Log

+--------------------------------------------+----------+---------------------+
|                    LOG                     | MINIKUBE | MINIKUBE (PR 10694) |
+--------------------------------------------+----------+---------------------+
| * minikube v1.18.0 on Debian               | 0.2s     | 0.2s                |
| 9.11 (kvm/amd64)                           |          |                     |
| * Using the docker driver                  | 0.1s     | 0.1s                |
| based on user configuration                |          |                     |
| * Starting control plane node              | 0.1s     | 0.1s                |
| minikube in cluster minikube               |          |                     |
| * Creating docker container                | 10.1s    | 9.8s                |
| (CPUs=2, Memory=3700MB) ...                |          |                     |
| * Preparing Kubernetes v1.20.2             | 15.6s    | 15.8s               |
| on Docker 20.10.3 ...                      |          |                     |
| * Verifying Kubernetes                     | 0.1s     | 0.1s                |
| components...                              |          |                     |
|   - Using image                            | 1.0s     | 0.9s                |
| gcr.io/k8s-minikube/storage-provisioner:v4 |          |                     |
| * Enabled addons:                          | 0.1s     | 0.1s                |
| storage-provisioner,                       |          |                     |
| default-storageclass                       |          |                     |
| * Done! kubectl is now                     | 0.0s     | 0.0s                |
| configured to use "minikube"               |          |                     |
| cluster and "default"                      |          |                     |
| namespace by default                       |          |                     |
+--------------------------------------------+----------+---------------------+

@minikube-pr-bot
Copy link

kvm2 Driver
Times for minikube: 72.5s 72.0s 70.2s
Average time for minikube: 71.5s

Times for Minikube (PR 10694): 66.8s 67.4s 69.0s
Average time for Minikube (PR 10694): 67.7s

Averages Time Per Log

+--------------------------------------------+----------+---------------------+
|                    LOG                     | MINIKUBE | MINIKUBE (PR 10694) |
+--------------------------------------------+----------+---------------------+
| * minikube v1.18.0 on Debian               | 0.0s     | 0.0s                |
| 9.11 (kvm/amd64)                           |          |                     |
| * Using the kvm2 driver based              | 0.0s     | 0.0s                |
| on user configuration                      |          |                     |
| * Starting control plane node              | 0.0s     | 0.0s                |
| minikube in cluster minikube               |          |                     |
| * Creating kvm2 VM (CPUs=2,                | 44.4s    | 41.2s               |
| Memory=3700MB, Disk=20000MB)               |          |                     |
| ...                                        |          |                     |
| * Preparing Kubernetes v1.20.2             | 9.2s     | 9.1s                |
| on Docker 20.10.3 ...                      |          |                     |
|   - Generating certificates                | 2.9s     | 3.2s                |
| and keys ...                               |          |                     |
|   - Booting up control plane               | 10.8s    | 10.6s               |
| ...                                        |          |                     |
|   - Configuring RBAC rules ...             | 1.4s     | 1.2s                |
| * Verifying Kubernetes                     | 0.1s     | 0.1s                |
| components...                              |          |                     |
|   - Using image                            | 1.9s     | 1.5s                |
| gcr.io/k8s-minikube/storage-provisioner:v4 |          |                     |
| * Enabled addons:                          | 0.8s     | 1.1s                |
| default-storageclass,                      |          |                     |
| storage-provisioner                        |          |                     |
| * Done! kubectl is now                     | 0.0s     | 0.0s                |
| configured to use "minikube"               |          |                     |
| cluster and "default"                      |          |                     |
| namespace by default                       |          |                     |
+--------------------------------------------+----------+---------------------+

docker Driver
Times for minikube: 28.0s 27.6s 26.6s
Average time for minikube: 27.4s

Times for Minikube (PR 10694): 28.1s 26.0s 26.6s
Average time for Minikube (PR 10694): 26.9s

Averages Time Per Log

+--------------------------------------------+----------+---------------------+
|                    LOG                     | MINIKUBE | MINIKUBE (PR 10694) |
+--------------------------------------------+----------+---------------------+
| * minikube v1.18.0 on Debian               | 0.2s     | 0.2s                |
| 9.11 (kvm/amd64)                           |          |                     |
| * Using the docker driver                  | 0.1s     | 0.1s                |
| based on user configuration                |          |                     |
| * Starting control plane node              | 0.1s     | 0.1s                |
| minikube in cluster minikube               |          |                     |
| * Creating docker container                | 10.1s    | 10.2s               |
| (CPUs=2, Memory=3700MB) ...                |          |                     |
| * Preparing Kubernetes v1.20.2             | 15.6s    | 15.1s               |
| on Docker 20.10.3 ...                      |          |                     |
| * Verifying Kubernetes                     | 0.1s     | 0.1s                |
| components...                              |          |                     |
|   - Using image                            | 1.1s     | 1.0s                |
| gcr.io/k8s-minikube/storage-provisioner:v4 |          |                     |
| * Enabled addons:                          | 0.1s     | 0.1s                |
| storage-provisioner,                       |          |                     |
| default-storageclass                       |          |                     |
| * Done! kubectl is now                     | 0.0s     | 0.0s                |
| configured to use "minikube"               |          |                     |
| cluster and "default"                      |          |                     |
| namespace by default                       |          |                     |
+--------------------------------------------+----------+---------------------+

@@ -254,11 +256,12 @@ func (k *Bootstrapper) init(cfg config.ClusterConfig) error {
}
return errors.Wrap(err, "wait")
}
kw.Close()
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this close should be after Wait

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When we get to this line, all the logs are in the pipeline but may not have finished being processed, so we close the pipeline. Closing the pipeline doesn't kill it, instead it writes EOF to the pipe and then prevents new writes. Once the pipeline is emptied it hits the EOF and calls wg.Done() (line 322) and then the wg.Wait() on the next line is unblocked.

tl;dr: If they were in the other order it would block forever because the pipeline processing would be waiting for a EOF which is only added on kw.Close().

Copy link
Member

@medyagh medyagh left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

lets pull upstream and verify the go mod tidy with go16

@k8s-ci-robot
Copy link
Contributor

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: medyagh, spowelljr

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:

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

@k8s-ci-robot k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Mar 3, 2021
@spowelljr
Copy link
Member Author

lets pull upstream and verify the go mod tidy with go16

Done, didn't make any changes to the files.

@medyagh medyagh merged commit 5682b34 into kubernetes:master Mar 3, 2021
hetong07 pushed a commit to hetong07/minikube that referenced this pull request Mar 4, 2021
Added WaitGroups to prevent stderr/stdout from being empty in error logs
@spowelljr spowelljr deleted the fixTruncatingLogs branch June 28, 2021 17:40
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
approved Indicates a PR has been approved by an approver from all required OWNERS files. cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. ok-to-test Indicates a non-member PR verified by an org member that is safe to test. size/M Denotes a PR that changes 30-99 lines, ignoring generated files.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

kubeadm stderr is occasionally truncated
5 participants