Migrate klog to klog.InfoS in pkg/kubelet

[hase1128]

What type of PR is this?
/kind cleanup

What this PR does / why we need it:

Ref:

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

Log output before migration

I0601 19:25:53.698080   16895 kubelet_getters.go:173] status for pod nginx-pod-127.0.0.1 updated to {Running [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-06-01 19:18:54 +0900 JST  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2020-06-01 19:18:54 +0900 JST  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-06-01 19:18:54 +0900 JST  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-06-01 19:18:54 +0900 JST  }]    127.0.0.1 172.17.0.4 [{172.17.0.4}] 2020-06-01 19:18:54 +0900 JST [] [{nginx-container {nil &ContainerStateRunning{StartedAt:2020-06-01 18:27:34 +0900 JST,} nil} {nil nil nil} true 0 nginx:latest docker-pullable://nginx@sha256:6fff55753e3b34e36e24e37039ee9eae1fe38a6420d8ae16ef37c92d1eb26699 docker://c729caca14fd6b19fb1fdbf5fe436352abd31c488a134fd5e56ee9fe7dc98eaa 0xc0012c2069}] BestEffort []}

After migration

I0601 19:45:29.666416   27921 kubelet_getters.go:173] "Pod status updated" pod="default/nginx-pod-127.0.0.1" status=v1.PodStatus{Phase:"Running", Conditions:[]v1.PodCondition{v1.PodCondition{Type:"Initialized", Status:"True", LastProbeTime:v1.Time{Time:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}}, LastTransitionTime:v1.Time{Time:time.Time{wall:0x0, ext:63726604110, loc:(*time.Location)(0x750f720)}}, Reason:"", Message:""}, v1.PodCondition{Type:"Ready", Status:"True", LastProbeTime:v1.Time{Time:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}}, LastTransitionTime:v1.Time{Time:time.Time{wall:0x0, ext:63726604110, loc:(*time.Location)(0x750f720)}}, Reason:"", Message:""}, v1.PodCondition{Type:"ContainersReady", Status:"True", LastProbeTime:v1.Time{Time:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}}, LastTransitionTime:v1.Time{Time:time.Time{wall:0x0, ext:63726604110, loc:(*time.Location)(0x750f720)}}, Reason:"", Message:""}, v1.PodCondition{Type:"PodScheduled", Status:"True", LastProbeTime:v1.Time{Time:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}}, LastTransitionTime:v1.Time{Time:time.Time{wall:0x0, ext:63726604110, loc:(*time.Location)(0x750f720)}}, Reason:"", Message:""}}, Message:"", Reason:"", NominatedNodeName:"", HostIP:"127.0.0.1", PodIP:"172.17.0.4", PodIPs:[]v1.PodIP{v1.PodIP{IP:"172.17.0.4"}}, StartTime:(*v1.Time)(0xc000d74220), InitContainerStatuses:[]v1.ContainerStatus(nil), ContainerStatuses:[]v1.ContainerStatus{v1.ContainerStatus{Name:"nginx-container", State:v1.ContainerState{Waiting:(*v1.ContainerStateWaiting)(nil), Running:(*v1.ContainerStateRunning)(0xc000d74200), Terminated:(*v1.ContainerStateTerminated)(nil)}, LastTerminationState:v1.ContainerState{Waiting:(*v1.ContainerStateWaiting)(nil), Running:(*v1.ContainerStateRunning)(nil), Terminated:(*v1.ContainerStateTerminated)(nil)}, Ready:true, RestartCount:0, Image:"nginx:latest", ImageID:"docker-pullable://nginx@sha256:6fff55753e3b34e36e24e37039ee9eae1fe38a6420d8ae16ef37c92d1eb26699", ContainerID:"docker://c729caca14fd6b19fb1fdbf5fe436352abd31c488a134fd5e56ee9fe7dc98eaa", Started:(*bool)(0xc000f7f1a9)}}, QOSClass:"BestEffort", EphemeralContainerStatuses:[]v1.ContainerStatus(nil)}

[k8s-ci-robot]

Hi @hase1128. 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 /ok-to-test on its own line. Until that is done, I will not automatically test new commits in this PR, but the usual testing commands by org members will still work. Regular contributors should join the org to skip this step.

Once the patch is verified, the new status will be reflected by the ok-to-test label.

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.

[hase1128]

/assign @yujuhong
/assign @serathius

[yuzhiquan]

/ok-to-test

[matthyx]

/kind cleanup
/priority important-longterm
/lgtm
/release-note-none

[serathius]

Looks like there is an regression in serializing v1.Time when it is a struct subfield. Created separate issue for it kubernetes/klog#156

Not sure if intention of this log was to dump whole status (conditions is very hard to read).
I think we should consider changing this log to use status.Phase instead of status.

[hase1128]

Looks like there is an regression in serializing v1.Time when it is a struct subfield. Created separate issue for it kubernetes/klog#156

Is there any task to do in this migration PR?

Not sure if intention of this log was to dump whole status (conditions is very hard to read).
I think we should consider changing this log to use status.Phase instead of status.

I think so too. This function updates status for static pod.
I think status is updated in this line, and we can get all Pod status information correctly by GetPods function. so, I don't know whether it is necessary to output all status information to the log or not.

FYI
Here is log output in case of using status.Phase.
I would like to use status.Phase if it's accepted.

Before migration

I0602 10:07:06.146242    7665 kubelet_getters.go:173] status for pod nginx-pod-127.0.0.1 updated to Running

After migration

I0602 09:58:05.157647   23653 kubelet_getters.go:173] "Pod status updated" pod="default/nginx-pod-127.0.0.1" status="Running"

[serathius]

I think it makes sense. Can you update the PR?
@yujuhong what's your opinion on this?

[hase1128]

I updated. (Using status.Phase)

[serathius]

So looks like change is:
Before

I0601 19:25:53.698080   16895 kubelet_getters.go:173] status for pod nginx-pod-127.0.0.1 updated to {Running [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-06-01 19:18:54 +0900 JST  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2020-06-01 19:18:54 +0900 JST  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-06-01 19:18:54 +0900 JST  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-06-01 19:18:54 +0900 JST  }]    127.0.0.1 172.17.0.4 [{172.17.0.4}] 2020-06-01 19:18:54 +0900 JST [] [{nginx-container {nil &ContainerStateRunning{StartedAt:2020-06-01 18:27:34 +0900 JST,} nil} {nil nil nil} true 0 nginx:latest docker-pullable://nginx@sha256:6fff55753e3b34e36e24e37039ee9eae1fe38a6420d8ae16ef37c92d1eb26699 docker://c729caca14fd6b19fb1fdbf5fe436352abd31c488a134fd5e56ee9fe7dc98eaa 0xc0012c2069}] BestEffort []}

After

I0602 09:58:05.157647   23653 kubelet_getters.go:173] "Pod status updated" pod="default/nginx-pod-127.0.0.1" status="Running"

/lgtm

[hase1128]

So looks like change is:

correct.

[hase1128]

/retest

[hase1128]

/retest

[serathius]

ping @yujuhong

[serathius]

Hey @Random-Liu can you approve this?

[Random-Liu]

/approve
/lgtm

[k8s-ci-robot]

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: hase1128, Random-Liu

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:

• pkg/kubelet/OWNERS [Random-Liu]

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

[serathius]

/retest

[serathius]

/retest