Add tool to check use of unstructured logs

[adisky]

Signed-off-by: Aditi Sharma adi.sky17@gmail.com

What type of PR is this?

/kind feature

What this PR does / why we need it:

It adds script hack/verify-structured-logging which reports use of unstructured logs. This script will be used to prevent regression after packages have been migrated to use structured logging.

Which issue(s) this PR fixes:

Ref #98975

Special notes for your reviewer:

This PR only adds the static check tool, scripts needs to be created to use this tool. Currently it only reports the use of unstructured logging functions. It could be improved for other checks like use of format specifiers.

Does this PR introduce a user-facing change?

NONE

Additional documentation e.g., KEPs (Kubernetes Enhancement Proposals), usage docs, etc.:

- [KEP]: https://github.com/kubernetes/enhancements/tree/master/keps/sig-instrumentation/1602-structured-logging

/sig instrumentation

[serathius]

Overall looks good, can you add tests like for metric stability analysis ?https://github.com/kubernetes/kubernetes/blob/master/test/instrumentation/main_test.go

[adisky]

Overall looks good, can you add tests like for metric stability analysis ?https://github.com/kubernetes/kubernetes/blob/master/test/instrumentation/main_test.go

sure, will update with tests.

[ehashman]

/triage accepted
/priority important-soon
/assign

[adisky]

It is not working currently for Verbose style logs klog.V(2).Infof(), Working on it and tests.

[ehashman]

Looking great thus far! I'm unfamiliar with the tool so I'm not yet sure how we'll handle the nested V(N) cases but looking forward to your solution.

My test run:

ehashman@red-dot:~/src/k8s/test/instrumentation/logcheck$ go run main.go analyzer.go ~/src/k8s/pkg/kubelet/lifecycle/
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/handlers.go:67:4: unstructured logging function "Infof" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/handlers.go:74:4: unstructured logging function "Infof" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/handlers.go:80:3: unstructured logging function "Errorf" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/handlers.go:113:4: unstructured logging function "Errorf" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/predicate.go:65:3: unstructured logging function "Errorf" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/predicate.go:79:3: unstructured logging function "Warningf" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/predicate.go:101:3: unstructured logging function "Warningf" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/predicate.go:113:4: unstructured logging function "Warningf" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/predicate.go:126:4: unstructured logging function "Warningf" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/predicate.go:139:4: unstructured logging function "Infof" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/predicate.go:143:4: unstructured logging function "Infof" should not be used
/home/ehashman/src/k8s/pkg/kubelet/lifecycle/predicate.go:147:4: unstructured logging function "Warningf" should not be used
exit status 3

[ehashman]

/cc @BenTheElder

if you have the chance to provide some early feedback on this static analysis we're writing to prevent structured logging regressions

[ehashman]

FWIW as well: I think we should have plenty of support to merge after code freeze if this misses it somehow, because this only alters tests not the release binaries, and test freeze is not until march 24th https://www.kubernetes.dev/resources/release/#tldr

.. but I think we can get this in before code freeze anyhow sweat_smile

The hope is to get this merged and included in CI before code freeze because it will validate that we've fully migrated pkg/kubelet and cmd/kubelet to structured logging, which is an acceptance criteria for structured logging graduation to beta.

[ehashman]

I think at this point the last thing remaining is to wire this into verify.sh?

[adisky]

I think at this point the last thing remaining is to wire this into verify.sh?

I added a verify script, is something else i am missing?
https://github.com/kubernetes/kubernetes/blob/5922c90e354e14fd38b4542ea087a7bf4606b8db/hack/verify-structured-logging.sh

[ehashman]

Yes, in order for this to run as part of make verify I believe https://github.com/kubernetes/kubernetes/blob/master/hack/make-rules/verify.sh needs to be updated.

[adisky]

It is running 🤔
https://prow.k8s.io/view/gs/kubernetes-jenkins/pr-logs/pull/99090/pull-kubernetes-verify/1367363075899920384#1:build-log.txt%3A2135

[BenTheElder]

Verify locates all hack/verify*.sh and runs them except for specific exclusions. Shouldn't need to change anything there.

[BenTheElder]

we indeed ran it in 13s, #99090 (comment) is my main remaining concern (it looks like this script can never exit failure currently?)

[BenTheElder]

this may also need

kubernetes/hack/verify-govet-levee.sh

Lines 30 to 31 in 792b4b1

	export GOBIN="${KUBE_OUTPUT_BINPATH}"
	PATH="${GOBIN}:${PATH}"

we don't want to install to the global GOBIN

[BenTheElder]

also needs a call to kube::golang::setup_env earlier I think (which will also validate the required go version if running this script by itself).

[ehashman]

Yes, the setup_env was required for me to run this locally.

[adisky]

Using kube::golang::setup_env not working for me locally, added kube::golang::verify_go_version, also I have checked other linting scripts they are not calling setup_env.
https://github.com/kubernetes/kubernetes/blob/master/hack/verify-staticcheck.sh

[BenTheElder]

kube::golang::setup_env is pretty standard, this is a bug in verify-staticcheck if anything https://cs.k8s.io/?q=kube%3A%3Agolang%3A%3Asetup_env&i=nope&files=&excludeFiles=&repos=

[adisky]

/test pull-kubernetes-unit

[ehashman]

/retest

[BenTheElder]

/lgtm
/approve
This is sufficient to iterate on, thank you.
/hold
One remaining check to consider: normally before merging a new lint like this we want to see that it will in fact fail on something, so we typically push a temporary commit to show this (e.g. adding a bad change in a covered file), then revert the change (giving CI runs reviewers can see).

[BenTheElder]

nit: seems spelling lint missed this, s/concurrency/concurrancy/ (not going to block on this during code freeze of all times!)

[BenTheElder]

Also hard data: this is taking 13s in CI which is fast enough for now (though nearly as slow as gofmt parsing the entire repo). The overall job takes 35m, but every bit counts (most of these tools are not easily made any faster, and we have removed some checks out of the default make verify to avoid excessive time creep).
Will investigate in follow-ups.

[BenTheElder]

because this operates on the source tree kube::golang::setup_env is needed to work for developers that do not have Kubernetes checked out to a GOPATH. we can do that in a follow-up though.

[k8s-ci-robot]

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: adisky, BenTheElder

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:

• hack/OWNERS [BenTheElder]

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

[ehashman]

Not sure if this is the best way to do this (because it will involve building twice) but I was able to fix kubernetes/klog#215 with the following patch:

Suggested change

	logcheck "$KUBE_ROOT/$package" || ret=$?
	GOOS=linux logcheck "$KUBE_ROOT/$package" || ret=$?
	GOOS=windows logcheck "$KUBE_ROOT/$package" || ret=$?

[ehashman]

/hold cancel

I've confirmed locally this fails against files not in the list. I'm going to follow up with a PR to update migrated files and update the guidance for structured logging PRs to add to this file.

[BenTheElder]

/retest
🤨