Convert cmd/kubelet/app/server.go to structured logging #98334

wawa0210 · 2021-01-24T05:49:24Z

What type of PR is this?

/kind bug

What this PR does / why we need it:

When the parameters are incorrect, kubelet only outputs the error log instead of the entire stack log
This way the user experience will be better and consistent with other components (such as kube-proxy)

Which issue(s) this PR fixes:

Fixes #98292

Special notes for your reviewer:
For compatibility, refer to klog.Fatalf Exit code remains 255

Does this PR introduce a user-facing change?:

NONE

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

/sig node
/area kubelet

wawa0210 · 2021-01-24T05:50:50Z

/assign @vishh

ehashman · 2021-01-25T19:19:32Z

/hold

Bug wasn't accepted and I'm not sure this is an improved user experience.

ehashman · 2021-01-25T19:21:36Z

Note: I think Fatal logs are going away anyways with the structured logging migration this release, so this PR will be replaced soon anyways. See: https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/migration-to-structured-logging.md#replacing-fatal-calls

It would be better to migrate this entire file to use structured logging rather than just making this change.

wawa0210 · 2021-01-26T00:47:37Z

It would be better to migrate this entire file to use structured logging rather than just making this change.

Understand, if possible, I want this pr to fix this bug alone (keep focus). Then reopen a pr to migrate the entire file to use structured logs. What do you think?

ehashman · 2021-01-26T03:04:59Z

It would be better to migrate this entire file to use structured logging rather than just making this change.

Understand, if possible, I want this pr to fix this bug alone (keep focus). Then reopen a pr to migrate the entire file to use structured logs. What do you think?

I would prefer you fix it all in one go, because migrating away from using Fatalf is part of the log migration, and we have limited reviewer/approver bandwidth.

ehashman

Thanks for doing this! I have a bit of feedback on the log changes.

ehashman · 2021-01-29T19:00:39Z

cmd/kubelet/app/server.go

@@ -117,7 +117,8 @@ func NewKubeletCommand() *cobra.Command {
 	kubeletConfig, err := options.NewKubeletConfiguration()
 	// programmer error
 	if err != nil {
-		klog.Fatal(err)
+		klog.ErrorS(err, "Failed create a new kubelet configuration")


Suggested change

klog.ErrorS(err, "Failed create a new kubelet configuration")

klog.ErrorS(err, "Failed to create a new kubelet configuration")

ehashman · 2021-01-29T19:04:03Z

cmd/kubelet/app/server.go

@@ -117,7 +117,8 @@ func NewKubeletCommand() *cobra.Command {
 	kubeletConfig, err := options.NewKubeletConfiguration()
 	// programmer error
 	if err != nil {
-		klog.Fatal(err)
+		klog.ErrorS(err, "Failed create a new kubelet configuration")
+		os.Exit(255)


Please use exit code 1 throughout this file, and not 255, to be consistent with the rest of the files in cmd/: https://cs.k8s.io/?q=os.Exit&i=nope&files=cmd%2F.*&repos=kubernetes/kubernetes

Because the error code of klog.Fatalf will return 255, in order not to break compatibility, I returned 255.
So I kept the status quo. Does it need to be adjusted to 1 here? Does it need to be discussed?

I'll ask in Slack about it.

we should not be using 255, but rather 1.
also idealy applications should have a single point of os.Exit() instead of multiple ones.

but as mentioned on slack this change would need an ACTION REQUIRED if users are expecting an exact value and not != 0

also idealy applications should have a single point of os.Exit() instead of multiple ones.

There are various reasons for calling os.Exit(1). If only one os.Exit() is needed, do you have any good suggestions?

deferring to the kubelet maintainers, but ideally errors should bubble up to a single point of os.Exit(x).
and there, depending on the different error types different exit codes can be returned.

kubernetes components tend to just os.Exit at arbitrary locations with fixed error codes, which is not a great pattern.

ehashman · 2021-01-29T19:06:58Z

cmd/kubelet/app/server.go

 			}

 			// check if there are non-flag arguments in the command line
 			cmds := cleanFlagSet.Args()
 			if len(cmds) > 0 {
 				cmd.Usage()
-				klog.Fatalf("unknown command: %s", cmds[0])
+				klog.InfoS("Unknown command", "command", cmds[0])


Fatal calls should use ErrorS, you can pass it a nil error rather than use InfoS: https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/migration-to-structured-logging.md#using-errors

/cc @serathius

ehashman · 2021-01-29T19:09:05Z

cmd/kubelet/app/server.go

@@ -534,7 +548,7 @@ func run(ctx context.Context, s *options.KubeletServer, kubeDeps *kubelet.Depend
 				return err
 			}
 			if cloud != nil {
-				klog.V(2).Infof("Successfully initialized cloud provider: %q from the config file: %q\n", s.CloudProvider, s.CloudConfigFile)
+				klog.V(2).InfoS("Successfully initialized cloud provider", "cloud provider", s.CloudProvider, "config file", s.CloudConfigFile)


Keys should not have spaces. I think the convention is to use camelCase (i.e. "cloudProvider")

ehashman · 2021-01-29T19:09:58Z

cmd/kubelet/app/server.go

@@ -611,14 +625,14 @@ func run(ctx context.Context, s *options.KubeletServer, kubeDeps *kubelet.Depend
 	cgroupRoots = append(cgroupRoots, nodeAllocatableRoot)
 	kubeletCgroup, err := cm.GetKubeletContainer(s.KubeletCgroups)
 	if err != nil {
-		klog.Warningf("failed to get the kubelet's cgroup: %v.  Kubelet system container metrics may be missing.", err)
+		klog.InfoS("Failed to get the kubelet's cgroup. Kubelet system container metrics may be missing.", "error", err)


Please use err instead of error for the key: https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/migration-to-structured-logging.md#name-arguments (same for the rest of the file)

ehashman · 2021-01-29T19:10:48Z

cmd/kubelet/app/server.go

@@ -677,15 +691,15 @@ func run(ctx context.Context, s *options.KubeletServer, kubeDeps *kubelet.Depend

 		if reservedSystemCPUs.Size() > 0 {
 			// at cmd option valication phase it is tested either --system-reserved-cgroup or --kube-reserved-cgroup is specified, so overwrite should be ok
-			klog.Infof("Option --reserved-cpus is specified, it will overwrite the cpu setting in KubeReserved=\"%v\", SystemReserved=\"%v\".", s.KubeReserved, s.SystemReserved)
+			klog.InfoS("Option --reserved-cpus is specified, it will overwrite the cpu setting in KubeReserved=\"%v\", SystemReserved=\"%v\".", s.KubeReserved, s.SystemReserved)


This log line needs to be updated, it still has string formatting

ehashman · 2021-01-29T19:10:58Z

cmd/kubelet/app/server.go

 			if s.KubeReserved != nil {
 				delete(s.KubeReserved, "cpu")
 			}
 			if s.SystemReserved == nil {
 				s.SystemReserved = make(map[string]string)
 			}
 			s.SystemReserved["cpu"] = strconv.Itoa(reservedSystemCPUs.Size())
-			klog.Infof("After cpu setting is overwritten, KubeReserved=\"%v\", SystemReserved=\"%v\"", s.KubeReserved, s.SystemReserved)
+			klog.InfoS("After cpu setting is overwritten, KubeReserved=\"%v\", SystemReserved=\"%v\"", s.KubeReserved, s.SystemReserved)


Also needs its string formatting updated

ehashman · 2021-01-29T19:11:27Z

cmd/kubelet/app/server.go

@@ -791,7 +805,7 @@ func run(ctx context.Context, s *options.KubeletServer, kubeDeps *kubelet.Depend
 		go wait.Until(func() {
 			err := http.ListenAndServe(net.JoinHostPort(s.HealthzBindAddress, strconv.Itoa(int(s.HealthzPort))), mux)
 			if err != nil {
-				klog.Errorf("Starting healthz server failed: %v", err)
+				klog.ErrorS(err, "Failed to starting healthz server")


Suggested change

klog.ErrorS(err, "Failed to starting healthz server")

klog.ErrorS(err, "Failed to start healthz server")

ehashman · 2021-01-29T19:12:12Z

cmd/kubelet/app/server.go

@@ -1093,7 +1107,7 @@ func RunKubelet(kubeServer *options.KubeletServer, kubeDeps *kubelet.Dependencie
 		for _, ip := range strings.Split(kubeServer.NodeIP, ",") {
 			parsedNodeIP := net.ParseIP(strings.TrimSpace(ip))
 			if parsedNodeIP == nil {
-				klog.Warningf("Could not parse --node-ip value %q; ignoring", ip)
+				klog.InfoS("Could not parse --node-ip ignoring", "nodeIp", ip)


Suggested change

klog.InfoS("Could not parse --node-ip ignoring", "nodeIp", ip)

klog.InfoS("Could not parse --node-ip ignoring", "nodeIP", ip)

ehashman · 2021-01-29T19:12:51Z

cmd/kubelet/app/server.go

@@ -1114,7 +1128,7 @@ func RunKubelet(kubeServer *options.KubeletServer, kubeDeps *kubelet.Dependencie
 	})

 	credentialprovider.SetPreferredDockercfgPath(kubeServer.RootDirectory)
-	klog.V(2).Infof("Using root directory: %v", kubeServer.RootDirectory)
+	klog.V(2).InfoS("Using root directory", "directory", kubeServer.RootDirectory)


@serathius do you have an opinion on directory vs. dir?

ehashman · 2021-01-29T19:14:59Z

/priority important-longterm
/triage accepted
/retitle Convert cmd/kubelet/app/server.go to structured logging

ehashman · 2021-03-11T19:56:54Z

/remove-kind bug
/kind cleanup

mrunalp · 2021-03-16T19:32:26Z

/approve

k8s-ci-robot · 2021-03-16T19:32:49Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: mrunalp, wawa0210

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:

~~cmd/kubelet/OWNERS~~ [mrunalp]

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

… instead of the entire stack log

ehashman

/lgtm

pacoxu · 2021-03-17T02:24:38Z

/retest

pacoxu · 2021-03-17T02:55:25Z

/remove-label needs-rebase

k8s-ci-robot · 2021-03-17T02:55:26Z

@pacoxu: The label(s) /remove-label needs-rebase cannot be applied. These labels are supported: api-review, tide/merge-method-merge, tide/merge-method-rebase, tide/merge-method-squash

In response to this:

/remove-label needs-rebase

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.

pacoxu · 2021-03-17T05:09:21Z

/retest

wawa0210 · 2021-03-17T05:36:51Z

/test pull-kubernetes-e2e-kind-ipv6

k8s-ci-robot requested review from mtaufen and yujuhong January 24, 2021 05:50

k8s-ci-robot assigned vishh Jan 24, 2021

ehashman added this to Needs Reviewer in SIG Node PR Triage Jan 25, 2021

k8s-ci-robot added the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Jan 25, 2021

ehashman moved this from Needs Reviewer to Waiting on Author in SIG Node PR Triage Jan 25, 2021

wawa0210 force-pushed the fix-98292 branch from 8012e58 to b386ba6 Compare January 29, 2021 07:19

k8s-ci-robot added size/L Denotes a PR that changes 100-499 lines, ignoring generated files. and removed size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels Jan 29, 2021

wawa0210 force-pushed the fix-98292 branch from b386ba6 to 109c93f Compare January 29, 2021 08:02

ehashman suggested changes Jan 29, 2021

View reviewed changes

k8s-ci-robot requested a review from serathius January 29, 2021 19:13

k8s-ci-robot added the priority/important-longterm Important over the long term, but may not be staffed and/or may need multiple releases to complete. label Jan 29, 2021

k8s-ci-robot changed the title ~~Fix kubelet flag verification failed, output error message instead of stack error~~ Convert cmd/kubelet/app/server.go to structured logging Jan 29, 2021

k8s-ci-robot added triage/accepted Indicates an issue or PR is ready to be actively worked on. and removed needs-priority Indicates a PR lacks a `priority/foo` label and requires one. labels Jan 29, 2021

k8s-ci-robot added this to the v1.21 milestone Mar 11, 2021

ehashman moved this from Waiting on Author to Needs Approver in SIG Node PR Triage Mar 11, 2021

ehashman moved this from Waiting on Author to Needs Approver in Structured Logging Migration for Kubelet, 1.21 Mar 11, 2021

k8s-ci-robot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Mar 11, 2021

k8s-ci-robot added kind/cleanup Categorizes issue or PR as related to cleaning up code, process, or technical debt. and removed kind/bug Categorizes issue or PR as related to a bug. labels Mar 11, 2021

mrunalp moved this from Needs Approver to Done in SIG Node PR Triage Mar 16, 2021

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Mar 16, 2021

ehashman moved this from Needs Approver to Done in Structured Logging Migration for Kubelet, 1.21 Mar 16, 2021

k8s-ci-robot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Mar 16, 2021

When the parameters are incorrect, kubelet only outputs the error log…

ae381fc

… instead of the entire stack log

wawa0210 force-pushed the fix-98292 branch from 27860cc to ae381fc Compare March 17, 2021 00:36

k8s-ci-robot removed the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Mar 17, 2021

ehashman reviewed Mar 17, 2021

View reviewed changes

k8s-ci-robot assigned ehashman Mar 17, 2021

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Mar 17, 2021

k8s-ci-robot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Mar 17, 2021

nikhita mentioned this pull request Mar 17, 2021

needs-rebase application is delayed, only seems to be triggered on comment kubernetes/test-infra#21006

Closed

k8s-ci-robot merged commit 1dce898 into kubernetes:master Mar 17, 2021

wawa0210 deleted the fix-98292 branch March 17, 2021 11:20

k8s-ci-robot added release-note-none Denotes a PR that doesn't merit a release note. and removed release-note Denotes a PR that will be considered when it comes time to generate release notes. labels Mar 29, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Convert cmd/kubelet/app/server.go to structured logging #98334

Convert cmd/kubelet/app/server.go to structured logging #98334

wawa0210 commented Jan 24, 2021 •

edited by liggitt

wawa0210 commented Jan 24, 2021

ehashman commented Jan 25, 2021

ehashman commented Jan 25, 2021

wawa0210 commented Jan 26, 2021

ehashman commented Jan 26, 2021

ehashman left a comment

ehashman Jan 29, 2021

ehashman Jan 29, 2021

wawa0210 Jan 30, 2021 •

edited

ehashman Feb 1, 2021

neolit123 Feb 1, 2021 •

edited

wawa0210 Feb 13, 2021

neolit123 Feb 13, 2021 •

edited

ehashman Jan 29, 2021

ehashman Jan 29, 2021

ehashman Jan 29, 2021

ehashman Jan 29, 2021

ehashman Jan 29, 2021

ehashman Jan 29, 2021

ehashman Jan 29, 2021

ehashman Jan 29, 2021

serathius Mar 9, 2021

ehashman commented Jan 29, 2021

ehashman commented Mar 11, 2021

mrunalp commented Mar 16, 2021

k8s-ci-robot commented Mar 16, 2021

ehashman left a comment

pacoxu commented Mar 17, 2021

pacoxu commented Mar 17, 2021

k8s-ci-robot commented Mar 17, 2021

pacoxu commented Mar 17, 2021

wawa0210 commented Mar 17, 2021

	klog.ErrorS(err, "Failed create a new kubelet configuration")
	klog.ErrorS(err, "Failed to create a new kubelet configuration")

	klog.ErrorS(err, "Failed to starting healthz server")
	klog.ErrorS(err, "Failed to start healthz server")

	klog.InfoS("Could not parse --node-ip ignoring", "nodeIp", ip)
	klog.InfoS("Could not parse --node-ip ignoring", "nodeIP", ip)

Convert cmd/kubelet/app/server.go to structured logging #98334

Convert cmd/kubelet/app/server.go to structured logging #98334

Conversation

wawa0210 commented Jan 24, 2021 • edited by liggitt

wawa0210 commented Jan 24, 2021

ehashman commented Jan 25, 2021

ehashman commented Jan 25, 2021

wawa0210 commented Jan 26, 2021

ehashman commented Jan 26, 2021

ehashman left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

wawa0210 Jan 30, 2021 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

neolit123 Feb 1, 2021 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

neolit123 Feb 13, 2021 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ehashman commented Jan 29, 2021

ehashman commented Mar 11, 2021

mrunalp commented Mar 16, 2021

k8s-ci-robot commented Mar 16, 2021

ehashman left a comment

Choose a reason for hiding this comment

pacoxu commented Mar 17, 2021

pacoxu commented Mar 17, 2021

k8s-ci-robot commented Mar 17, 2021

pacoxu commented Mar 17, 2021

wawa0210 commented Mar 17, 2021

wawa0210 commented Jan 24, 2021 •

edited by liggitt

wawa0210 Jan 30, 2021 •

edited

neolit123 Feb 1, 2021 •

edited

neolit123 Feb 13, 2021 •

edited