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.

Sign up for GitHub

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

Jump to bottom

Fix logging when JSON output selected #13955

Merged
merged 1 commit into from
Apr 14, 2022
Merged

Fix logging when JSON output selected #13955

merged 1 commit into from
Apr 14, 2022

Conversation

spowelljr
Copy link
Member

Fixes #13925

Case 1: Stop non-existing cluster
Before (notice log file is empty):

$ minikube stop -o json --log_file ./logs.txt 
{"specversion":"1.0","id":"805268b9-44d9-4bc5-8304-b2702c597744","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.info","datacontenttype":"application/json","data":{"message":"Profile \"minikube\" not found. Run \"minikube profile list\" to view all profiles."}}
{"specversion":"1.0","id":"15e5123f-278b-4e71-883e-0328255c25a5","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.info","datacontenttype":"application/json","data":{"message":"To start a cluster, run: \"minikube start\""}}

$ cat ./logs.txt 
Log file created at: 2022/04/12 11:02:30
Running on machine: powellsteven-macbookpro
Binary: Built with gc go1.18 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg

After:

$ minikube stop -o json --log_file ./logs.txt 
{"specversion":"1.0","id":"4bf92619-905c-4cfb-ab76-29b1901b7a14","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.info","datacontenttype":"application/json","data":{"message":"Profile \"minikube\" not found. Run \"minikube profile list\" to view all profiles."}}
{"specversion":"1.0","id":"6a1878be-e73d-4d6a-9989-044f9fbaeec6","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.info","datacontenttype":"application/json","data":{"message":"To start a cluster, run: \"minikube start\""}}

$ cat ./logs.txt
Log file created at: 2022/04/12 11:12:28
Running on machine: powellsteven-macbookpro
Binary: Built with gc go1.18 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0412 11:12:28.207325   29788 out.go:293] Setting OutFile to fd 1 ...
I0412 11:12:28.207650   29788 out.go:345] isatty.IsTerminal(1) = true
I0412 11:12:28.207653   29788 out.go:306] Setting ErrFile to fd 2...
I0412 11:12:28.207662   29788 out.go:345] isatty.IsTerminal(2) = true
I0412 11:12:28.207766   29788 root.go:315] Updating PATH: /Users/powellsteven/.minikube/bin
I0412 11:12:28.207955   29788 out.go:300] Setting JSON to true
I0412 11:12:28.207987   29788 mustload.go:65] Loading cluster: minikube
I0412 11:12:28.228382   29788 out.go:169] Profile "minikube" not found. Run "minikube profile list" to view all profiles.
I0412 11:12:28.247915   29788 out.go:169] To start a cluster, run: "minikube start"

Case 2: Successful start
Before (notice last line of log file is missing, last line should say "Done!"):

$ minikube start -o json
{"specversion":"1.0","id":"0fa63a84-b9e2-4071-9af3-4eddc053edf6","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"0","message":"minikube v1.25.2 on Darwin 12.3.1","name":"Initial Minikube Setup","totalsteps":"19"}}
{"specversion":"1.0","id":"919f9bb6-9015-4a4d-afe2-66c8369126a7","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"1","message":"Automatically selected the hyperkit driver","name":"Selecting Driver","totalsteps":"19"}}
{"specversion":"1.0","id":"34be6b7f-e921-4a2e-adad-40295fc017ca","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"3","message":"Starting control plane node minikube in cluster minikube","name":"Starting Node","totalsteps":"19"}}
{"specversion":"1.0","id":"88dd6b06-4765-4afc-8334-f9f80a1ed784","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"9","message":"Creating hyperkit VM (CPUs=2, Memory=4000MB, Disk=20000MB) ...","name":"Creating VM","totalsteps":"19"}}
{"specversion":"1.0","id":"52cef778-aa9e-4631-9015-377a9d42d8d2","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"11","message":"Preparing Kubernetes v1.23.5 on Docker 20.10.14 ...","name":"Preparing Kubernetes","totalsteps":"19"}}
{"specversion":"1.0","id":"d1aceff7-63ac-430a-87be-27f017aa86d1","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"12","message":"Generating certificates and keys ...","name":"Generating certificates","totalsteps":"19"}}
{"specversion":"1.0","id":"a4f3487a-723f-4e58-bfbc-5d2d0c2a4187","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"13","message":"Booting up control plane ...","name":"Booting control plane","totalsteps":"19"}}
{"specversion":"1.0","id":"f1c5d865-7e9b-4583-b6d1-96f7666d5f76","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"14","message":"Configuring RBAC rules ...","name":"Configuring RBAC rules","totalsteps":"19"}}
{"specversion":"1.0","id":"32a40912-005c-4cab-819d-c1e51d42bde7","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"17","message":"Verifying Kubernetes components...","name":"Verifying Kubernetes","totalsteps":"19"}}
{"specversion":"1.0","id":"865e9095-c4c5-4321-a59d-8d5918424205","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.info","datacontenttype":"application/json","data":{"message":"Using image gcr.io/k8s-minikube/storage-provisioner:v5"}}
{"specversion":"1.0","id":"13a51a58-c0b2-4472-be49-5b7e2cf36225","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"18","message":"Enabled addons: storage-provisioner, default-storageclass","name":"Enabling Addons","totalsteps":"19"}}
{"specversion":"1.0","id":"a88e8a1a-3cc5-43d2-96ba-0deadeb20fe9","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"19","message":"Done! kubectl is now configured to use \"minikube\" cluster and \"default\" namespace by default","name":"Done","totalsteps":"19"}}

$ cat ~/.minikube/logs/lastStart.txt
Log file created at: 2022/04/12 11:03:37
Running on machine: powellsteven-macbookpro
Binary: Built with gc go1.18 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0412 11:03:37.164976   28764 out.go:297] Setting OutFile to fd 1 ...
...
I0412 11:04:12.974597   28764 start.go:498] kubectl: 1.22.2, cluster: 1.23.5 (minor skew: 1)

After:

$ minikube start -o json
{"specversion":"1.0","id":"a0a5d962-1b20-4e41-9681-c175071e9249","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"0","message":"minikube v1.25.2 on Darwin 12.3.1","name":"Initial Minikube Setup","totalsteps":"19"}}
{"specversion":"1.0","id":"06f8c27f-4d46-4a03-82f0-5bb258cb54b6","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"1","message":"Automatically selected the hyperkit driver","name":"Selecting Driver","totalsteps":"19"}}
{"specversion":"1.0","id":"42f3d207-217e-4d5b-aa2f-03e9a56a857c","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"3","message":"Starting control plane node minikube in cluster minikube","name":"Starting Node","totalsteps":"19"}}
{"specversion":"1.0","id":"cdd04ceb-6a97-4999-8ceb-ed4773d82f59","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"9","message":"Creating hyperkit VM (CPUs=2, Memory=4000MB, Disk=20000MB) ...","name":"Creating VM","totalsteps":"19"}}
{"specversion":"1.0","id":"7709b512-3fef-4495-b751-1505d39207d4","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"11","message":"Preparing Kubernetes v1.23.5 on Docker 20.10.14 ...","name":"Preparing Kubernetes","totalsteps":"19"}}
{"specversion":"1.0","id":"055662ef-98f5-48d0-a6f9-19b896d20cbc","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"12","message":"Generating certificates and keys ...","name":"Generating certificates","totalsteps":"19"}}
{"specversion":"1.0","id":"1e037fe8-ca07-43e0-94b8-02dfce11fce7","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"13","message":"Booting up control plane ...","name":"Booting control plane","totalsteps":"19"}}
{"specversion":"1.0","id":"9da607b2-4593-4d7c-9526-4b4dd8de8d5d","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"14","message":"Configuring RBAC rules ...","name":"Configuring RBAC rules","totalsteps":"19"}}
{"specversion":"1.0","id":"8fb0af38-97f4-4592-8dc5-77029e866099","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"17","message":"Verifying Kubernetes components...","name":"Verifying Kubernetes","totalsteps":"19"}}
{"specversion":"1.0","id":"e37b7025-d1fd-486c-8335-84617d781cbf","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.info","datacontenttype":"application/json","data":{"message":"Using image gcr.io/k8s-minikube/storage-provisioner:v5"}}
{"specversion":"1.0","id":"370fb325-8369-4647-a18a-9906d0259821","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"18","message":"Enabled addons: storage-provisioner, default-storageclass","name":"Enabling Addons","totalsteps":"19"}}
{"specversion":"1.0","id":"a5c27dae-7565-40dc-ae64-fa668928db28","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"19","message":"Done! kubectl is now configured to use \"minikube\" cluster and \"default\" namespace by default","name":"Done","totalsteps":"19"}}

$ cat ~/.minikube/logs/lastStart.txt
Log file created at: 2022/04/12 11:13:43
Running on machine: powellsteven-macbookpro
Binary: Built with gc go1.18 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0412 11:13:43.168335   29869 out.go:293] Setting OutFile to fd 1 ...
...
I0412 11:14:21.700196   29869 out.go:97] Done! kubectl is now configured to use "minikube" cluster and "default" namespace by default

Case 3: Start with error
Before (notice log file is empty):

$ minikube start --driver docker -o json
{"specversion":"1.0","id":"9ed85d27-cfb8-44a0-8bf8-5fe1088bcb1c","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"0","message":"minikube v1.25.2 on Darwin 12.3.1","name":"Initial Minikube Setup","totalsteps":"19"}}
{"specversion":"1.0","id":"6fa3c00e-79bf-4fe9-a6fc-cc5e1818a0e9","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"1","message":"Using the docker driver based on user configuration","name":"Selecting Driver","totalsteps":"19"}}
{"specversion":"1.0","id":"46eeb209-3306-406f-b7ea-414c77633d43","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.error","datacontenttype":"application/json","data":{"advice":"Start the Docker service","exitcode":"63","issues":"","message":"\"docker version --format -\" exit status 1: Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?","name":"PROVIDER_DOCKER_NOT_RUNNING","url":"https://minikube.sigs.k8s.io/docs/drivers/docker/"}}

$ cat ~/.minikube/logs/lastStart.txt
Log file created at: 2022/04/12 11:07:08
Running on machine: powellsteven-macbookpro
Binary: Built with gc go1.18 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg

After:

$ minikube start --driver docker -o json
{"specversion":"1.0","id":"f0c2adc5-6301-44d4-8e7e-68220d4cad50","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"0","message":"minikube v1.25.2 on Darwin 12.3.1","name":"Initial Minikube Setup","totalsteps":"19"}}
{"specversion":"1.0","id":"f5c48718-f13c-47a9-8d8d-9b5399c9efd1","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.step","datacontenttype":"application/json","data":{"currentstep":"1","message":"Using the docker driver based on user configuration","name":"Selecting Driver","totalsteps":"19"}}
{"specversion":"1.0","id":"32537f22-9fc6-47ec-b59e-1eb73c704596","source":"https://minikube.sigs.k8s.io/","type":"io.k8s.sigs.minikube.error","datacontenttype":"application/json","data":{"advice":"Start the Docker service","exitcode":"63","issues":"","message":"\"docker version --format -\" exit status 1: Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?","name":"PROVIDER_DOCKER_NOT_RUNNING","url":"https://minikube.sigs.k8s.io/docs/drivers/docker/"}}

$ cat ~/.minikube/logs/lastStart.txt
Log file created at: 2022/04/12 11:16:30
Running on machine: powellsteven-macbookpro
Binary: Built with gc go1.18 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I0412 11:16:30.126288   30215 out.go:293] Setting OutFile to fd 1 ...
I0412 11:16:30.126486   30215 out.go:345] isatty.IsTerminal(1) = true
I0412 11:16:30.126489   30215 out.go:306] Setting ErrFile to fd 2...
I0412 11:16:30.126495   30215 out.go:345] isatty.IsTerminal(2) = true
I0412 11:16:30.126608   30215 root.go:315] Updating PATH: /Users/powellsteven/.minikube/bin
I0412 11:16:30.126983   30215 out.go:300] Setting JSON to true
I0412 11:16:30.158717   30215 start.go:114] hostinfo: {"hostname":"powellsteven-macbookpro.roam.corp.google.com","uptime":347772,"bootTime":1649439618,"procs":520,"os":"darwin","platform":"darwin","platformFamily":"Standalone Workstation","platformVersion":"12.3.1","kernelVersion":"21.4.0","kernelArch":"x86_64","virtualizationSystem":"","virtualizationRole":"","hostId":"2617b539-b948-5b0b-a8d8-43f2e62b1b0c"}
W0412 11:16:30.158832   30215 start.go:122] gopshost.Virtualization returned error: not implemented yet
I0412 11:16:30.179133   30215 out.go:97] minikube v1.25.2 on Darwin 12.3.1
I0412 11:16:30.179415   30215 notify.go:193] Checking for updates...
I0412 11:16:30.180041   30215 driver.go:346] Setting default libvirt URI to qemu:///system
W0412 11:16:30.268894   30215 docker.go:113] docker version returned error: exit status 1
I0412 11:16:30.288211   30215 out.go:97] Using the docker driver based on user configuration
I0412 11:16:30.288287   30215 start.go:283] selected driver: docker
I0412 11:16:30.288307   30215 start.go:800] validating driver "docker" against <nil>
I0412 11:16:30.288337   30215 start.go:811] status for docker: {Installed:true Healthy:false Running:false NeedsImprovement:false Error:"docker version --format {{.Server.Os}}-{{.Server.Version}}" exit status 1: Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running? Reason:PROVIDER_DOCKER_NOT_RUNNING Fix:Start the Docker service Doc:https://minikube.sigs.k8s.io/docs/drivers/docker/ Version:}
I0412 11:16:30.326318   30215 out.go:169]
W0412 11:16:30.351670   30215 out.go:228] "docker version --format -" exit status 1: Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?
W0412 11:16:30.351849   30215 out.go:228] Suggestion: Start the Docker service
W0412 11:16:30.351950   30215 out.go:228] Documentation: https://minikube.sigs.k8s.io/docs/drivers/docker/
I0412 11:16:30.371546   30215 out.go:169]

@k8s-ci-robot k8s-ci-robot added cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Apr 12, 2022
@k8s-ci-robot k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Apr 12, 2022
@k8s-ci-robot
Copy link
Contributor

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: klaases, 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

@spowelljr spowelljr merged commit cc90573 into kubernetes:master Apr 14, 2022
@spowelljr spowelljr deleted the fixLoggingJSON branch April 14, 2022 16:34
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@klaases klaases klaases approved these changes

@afbjorklund afbjorklund Awaiting requested review from afbjorklund

@prezha prezha Awaiting requested review from prezha

Assignees
No one assigned
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. size/M Denotes a PR that changes 30-99 lines, ignoring generated files.
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

No output to last start file with -o json passed to minikube start
3 participants
@spowelljr @k8s-ci-robot @klaases