-
Notifications
You must be signed in to change notification settings - Fork 4.9k
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
Generate one log file per minikube command #10425
Conversation
Thanks for your pull request. Before we can look at your pull request, you'll need to sign a Contributor License Agreement (CLA). 📝 Please follow instructions at https://git.k8s.io/community/CLA.md#the-contributor-license-agreement to sign the CLA. It may take a couple minutes for the CLA signature to be fully registered; after that, please reply here with a new comment and we'll verify. Thanks.
Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. I understand the commands that are listed here. |
Welcome @bharathkkb! |
Hi @bharathkkb. Thanks for your PR. I'm waiting for a kubernetes member to verify that this patch is reasonable to test. If it is, they should reply with Once the patch is verified, the new status will be reflected by the I understand the commands that are listed here. Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. |
Can one of the admins verify this patch? |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
this is a good PR, thank @bharathkkb for fixing this.
we will need to update the documentation on the https://minikube.sigs.k8s.io/docs/handbook/troubleshooting/
since the command we suggest to find log files wont be correct anymore
find $TMPDIR -mtime -1 -type f -name "*minikube*INFO*" -ls 2>/dev/null
(or can we make it in a way that the same suggestion on the site still works?)
I had to change it to not have the *INFO
find $TMPDIR -mtime -1 -type f -name "*minikube*" -ls 2>/dev/null
and I confirmed your fix only creates one file per command.
is it possible that we set a limit on how big this file can be ? maybe do not allow it to be bigger than 1 mb ?
medya@~/workspace/minikube (fix-multiple-log-files) $ cat /var/folders/s8/wxxccj3x7mncysv_zzm5w_r400h78j/T//minikube_version_a24f39ccb0b3c744e7472b70ec1372730a3ee53d.log
Log file created at: 2021/02/12 12:18:27
Running on machine: medya-macbookpro3
Binary: Built with gc go1.15.6 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0212 12:18:27.500643 18787 out.go:229] Setting OutFile to fd 1 ...
I0212 12:18:27.500936 18787 out.go:281] isatty.IsTerminal(1) = true
I0212 12:18:27.500939 18787 out.go:242] Setting ErrFile to fd 2...
I0212 12:18:27.500942 18787 out.go:281] isatty.IsTerminal(2) = true
I0212 12:18:27.501025 18787 root.go:307] Updating PATH: /Users/medya/.minikube/bin
I0212 12:18:27.526953 18787 out.go:119] minikube version: v1.17.1
I0212 12:18:27.551752 18787 out.go:119] commit: a44e009c6d54971d208f2e2789fc8473b0bec789
Log file created at: 2021/02/12 12:18:57
Running on machine: medya-macbookpro3
Binary: Built with gc go1.15.6 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0212 12:18:57.434975 18896 out.go:229] Setting OutFile to fd 1 ...
I0212 12:18:57.435169 18896 out.go:281] isatty.IsTerminal(1) = true
I0212 12:18:57.435172 18896 out.go:242] Setting ErrFile to fd 2...
I0212 12:18:57.435175 18896 out.go:281] isatty.IsTerminal(2) = true
I0212 12:18:57.435264 18896 root.go:307] Updating PATH: /Users/medya/.minikube/bin
I0212 12:18:57.461203 18896 out.go:119] minikube version: v1.17.1
I0212 12:18:57.485673 18896 out.go:119] commit: a44e009c6d54971d208f2e2789fc8473b0bec789
Log file created at: 2021/02/12 12:18:58
Running on machine: medya-macbookpro3
Binary: Built with gc go1.15.6 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0212 12:18:58.228372 18911 out.go:229] Setting OutFile to fd 1 ...
I0212 12:18:58.228561 18911 out.go:281] isatty.IsTerminal(1) = true
I0212 12:18:58.228564 18911 out.go:242] Setting ErrFile to fd 2...
I0212 12:18:58.228567 18911 out.go:281] isatty.IsTerminal(2) = true
I0212 12:18:58.228650 18911 root.go:307] Updating PATH: /Users/medya/.minikube/bin
I0212 12:18:58.254501 18911 out.go:119] minikube version: v1.17.1
I0212 12:18:58.279179 18911 out.go:119] commit: a44e009c6d54971d208f2e2789fc8473b0bec789
Log file created at: 2021/02/12 12:19:23
Running on machine: medya-macbookpro3
Binary: Built with gc go1.15.6 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0212 12:19:23.902215 18946 out.go:229] Setting OutFile to fd 1 ...
I0212 12:19:23.902501 18946 out.go:281] isatty.IsTerminal(1) = true
I0212 12:19:23.902503 18946 out.go:242] Setting ErrFile to fd 2...
I0212 12:19:23.902507 18946 out.go:281] isatty.IsTerminal(2) = true
I0212 12:19:23.902590 18946 root.go:307] Updating PATH: /Users/medya/.minikube/bin
I0212 12:19:23.928504 18946 out.go:119] minikube version: v1.17.1
I0212 12:19:23.953217 18946 out.go:119] commit: a44e009c6d54971d208f2e2789fc8473b0bec789
Log file created at: 2021/02/12 12:19:35
Running on machine: medya-macbookpro3
Binary: Built with gc go1.15.6 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0212 12:19:35.165196 18989 out.go:229] Setting OutFile to fd 1 ...
I0212 12:19:35.165391 18989 out.go:281] isatty.IsTerminal(1) = true
I0212 12:19:35.165393 18989 out.go:242] Setting ErrFile to fd 2...
I0212 12:19:35.165397 18989 out.go:281] isatty.IsTerminal(2) = true
I0212 12:19:35.165479 18989 root.go:307] Updating PATH: /Users/medya/.minikube/bin
I0212 12:19:35.191324 18989 out.go:119] minikube version: v1.17.1
I0212 12:19:35.216018 18989 out.go:119] commit: a44e009c6d54971d208f2e2789fc8473b0bec789
Log file created at: 2021/02/12 12:19:35
Running on machine: medya-macbookpro3
Binary: Built with gc go1.15.6 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0212 12:19:35.818268 19004 out.go:229] Setting OutFile to fd 1 ...
I0212 12:19:35.818565 19004 out.go:281] isatty.IsTerminal(1) = true
I0212 12:19:35.818568 19004 out.go:242] Setting ErrFile to fd 2...
I0212 12:19:35.818571 19004 out.go:281] isatty.IsTerminal(2) = true
I0212 12:19:35.818649 19004 root.go:307] Updating PATH: /Users/medya/.minikube/bin
I0212 12:19:35.844603 19004 out.go:119] minikube version: v1.17.1
I0212 12:19:35.869088 19004 out.go:119] commit: a44e009c6d54971d208f2e2789fc8473b0bec789
Log file created at: 2021/02/12 12:19:36
Running on machine: medya-macbookpro3
Binary: Built with gc go1.15.6 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0212 12:19:36.483261 19019 out.go:229] Setting OutFile to fd 1 ...
I0212 12:19:36.483460 19019 out.go:281] isatty.IsTerminal(1) = true
I0212 12:19:36.483463 19019 out.go:242] Setting ErrFile to fd 2...
I0212 12:19:36.483466 19019 out.go:281] isatty.IsTerminal(2) = true
I0212 12:19:36.483561 19019 root.go:307] Updating PATH: /Users/medya/.minikube/bin
I0212 12:19:36.509380 19019 out.go:119] minikube version: v1.17.1
I0212 12:19:36.534035 19019 out.go:119] commit: a44e009c6d54971d208f2e2789fc8473b0bec789
I really like that every command has its own log file
|
maybe we can have one log file per profile (limited with some max size)? |
@bharathkkb I like this PR, would u like to address the TODO and send it for final review to be merged? |
Hi @medyagh |
CC @spowelljr our new klog expert for a review |
@medyagh |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks for submitting this fix! Left a comment around the integration test.
test/integration/error_log_test.go
Outdated
{ | ||
command: "start", | ||
args: append([]string{"--memory=2200", "--wait=true"}, StartArgs()...), | ||
runCount: 20, // calling this 20 times should create 2 files with 1 greater than 1M |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm concerned about running minikube start
20 times for this test -- this subtest will take minimum 15 minutes to run.
Instead I would remove the minikube start
subtest entirely and run minikube status
100 times (or whatever it takes) to make sure 2 log files are created.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@priyawadhwa did a quick test and for around 500 times x minikube status
only generates 87K, so we may need quite a lot of status calls (~5K) to fill up 1M and create 2 files.
Another alternative might be to fill up the log with some mock data(<1M) and expect that minikube handles the creation of new log correctly on subsequent calls. However not sure if that would be a best practice since this is an integration test.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@bharathkkb Maybe try minikube logs
much shorter running time than start and generates quite a few logs.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@bharathkkb i really like that added integration test, I agree with @priyawadhwa lets try this test as a Sub Test for TestErrorSpam
we should not start a new cluster for this test, and it goes well with logging and spammming.
since we dont wanna spam TMPFolder
we can have a sub test that runs minikube start --dry-run
or minikube version
test/integration/error_log_test.go
Outdated
{ | ||
command: "start", | ||
args: append([]string{"--memory=2200", "--wait=true"}, StartArgs()...), | ||
runCount: 20, // calling this 20 times should create 2 files with 1 greater than 1M |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@bharathkkb i really like that added integration test, I agree with @priyawadhwa lets try this test as a Sub Test for TestErrorSpam
we should not start a new cluster for this test, and it goes well with logging and spammming.
since we dont wanna spam TMPFolder
we can have a sub test that runs minikube start --dry-run
or minikube version
add max log size, add tests, update website docs fix func comments address comments fix docs fail fast add tests to TestErrorSpam, switch to using log
95bf4e9
to
015b721
Compare
@medyagh I have switched this over to a subtest (let me know if this what you had in mind) and instead of |
/ok-to-test |
kvm2 Driver Times for Minikube (PR 10425): 71.3s 66.3s 71.5s Averages Time Per Log
docker Driver Times for Minikube (PR 10425): 27.7s 27.0s 27.1s Averages Time Per Log
|
@bharathkkb in the test Error Spam I see this
are we spamming the UI with stderr ? |
@bharathkkb lets fix the test and then it looks good |
hi @bharathkkb gentel reminder about this PR |
kvm2 Driver Times for Minikube (PR 10425): 65.3s 63.5s 65.9s Averages Time Per Log
docker Driver Times for Minikube (PR 10425): 25.6s 26.4s 27.6s Averages Time Per Log
|
@medyagh @spowelljr However looking at the tests I still see that there are cases where the logs could not be cleaned up causing failures. Are the tests being run in parallel on the same runner? Another workaround could be instead of just using the cmd to match logfiles, we can generate the expected SHA and use that to match instead. |
[APPROVALNOTIFIER] This PR is APPROVED This pull-request has been approved by: bharathkkb, medyagh 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 |
fixes #9156 based on #9156 (comment)
log_file
is not specified, we write to$TMPDIR/minikube_<argv[1]>_<hash>.log
log_dir
specified, we write to$LOG_DIR/minikube_<argv[1]>_<hash>.log
before
creates
each containing
after
creates
containing