From 6af7eb6d494d8f742e18a3b965053e3a518bf6d7 Mon Sep 17 00:00:00 2001 From: Elana Hashman Date: Wed, 17 Mar 2021 14:48:16 -0700 Subject: [PATCH] Migrate missed log entries in kubelet Co-Authored-By: pacoxu --- cmd/kubelet/app/init_windows.go | 2 +- cmd/kubelet/app/plugins_providers.go | 2 +- cmd/kubelet/app/server.go | 3 +-- pkg/kubelet/cm/container_manager_windows.go | 4 ++-- pkg/kubelet/cm/cpumanager/fake_cpu_manager.go | 2 +- .../cm/devicemanager/device_plugin_stub.go | 2 +- pkg/kubelet/cm/devicemanager/manager.go | 4 ++-- pkg/kubelet/config/file_unsupported.go | 2 +- pkg/kubelet/kubelet.go | 12 ++++------ pkg/kubelet/kubelet_pods.go | 2 +- pkg/kubelet/kubelet_volumes.go | 6 ++--- pkg/kubelet/prober/prober.go | 22 +++++++++---------- pkg/kubelet/prober/prober_manager.go | 2 +- pkg/kubelet/status/status_manager.go | 2 +- 14 files changed, 31 insertions(+), 36 deletions(-) diff --git a/cmd/kubelet/app/init_windows.go b/cmd/kubelet/app/init_windows.go index bed76806701..8b2755cc30d 100644 --- a/cmd/kubelet/app/init_windows.go +++ b/cmd/kubelet/app/init_windows.go @@ -52,7 +52,7 @@ func initForOS(windowsService bool, windowsPriorityClass string) error { } kubeletProcessHandle := windows.CurrentProcess() // Set the priority of the kubelet process to given priority - klog.Infof("Setting the priority of kubelet process to %s", windowsPriorityClass) + klog.InfoS("Setting the priority of kubelet process", "windowsPriorityClass", windowsPriorityClass) if err := windows.SetPriorityClass(kubeletProcessHandle, priority); err != nil { return err } diff --git a/cmd/kubelet/app/plugins_providers.go b/cmd/kubelet/app/plugins_providers.go index a3aecf140f8..6eead0b5f6a 100644 --- a/cmd/kubelet/app/plugins_providers.go +++ b/cmd/kubelet/app/plugins_providers.go @@ -52,7 +52,7 @@ func appendPluginBasedOnFeatureFlags(plugins []volume.VolumePlugin, inTreePlugin return plugins, nil } if featureGate.Enabled(pluginInfo.pluginUnregisterFeature) { - klog.Infof("Skipped registration of plugin since feature flag is enabled", "pluginName", inTreePluginName, "featureFlag", pluginInfo.pluginUnregisterFeature) + klog.InfoS("Skipped registration of plugin since feature flag is enabled", "pluginName", inTreePluginName, "featureFlag", pluginInfo.pluginUnregisterFeature) return plugins, nil } diff --git a/cmd/kubelet/app/server.go b/cmd/kubelet/app/server.go index 6fd37bf03e4..2dc10a512b3 100644 --- a/cmd/kubelet/app/server.go +++ b/cmd/kubelet/app/server.go @@ -285,10 +285,9 @@ HTTP server: The kubelet can also listen for HTTP and respond to a simple API config.StaticPodURLHeader[k] = []string{""} } // log the kubelet's config for inspection - klog.V(5).Infof("KubeletConfiguration: %#v", config) + klog.V(5).InfoS("KubeletConfiguration", "configuration", kubeletServer.KubeletConfiguration) // run the kubelet - klog.V(5).InfoS("KubeletConfiguration", "configuration", kubeletServer.KubeletConfiguration) if err := Run(ctx, kubeletServer, kubeletDeps, utilfeature.DefaultFeatureGate); err != nil { klog.ErrorS(err, "Failed to run kubelet") os.Exit(1) diff --git a/pkg/kubelet/cm/container_manager_windows.go b/pkg/kubelet/cm/container_manager_windows.go index 041d90f365a..3b1cf9430ef 100644 --- a/pkg/kubelet/cm/container_manager_windows.go +++ b/pkg/kubelet/cm/container_manager_windows.go @@ -73,7 +73,7 @@ func (cm *containerManagerImpl) Start(node *v1.Node, sourcesReady config.SourcesReady, podStatusProvider status.PodStatusProvider, runtimeService internalapi.RuntimeService) error { - klog.V(2).Infof("Starting Windows container manager") + klog.V(2).InfoS("Starting Windows container manager") if utilfeature.DefaultFeatureGate.Enabled(kubefeatures.LocalStorageCapacityIsolation) { rootfs, err := cm.cadvisorInterface.RootFsInfo() @@ -112,7 +112,7 @@ func NewContainerManager(mountUtil mount.Interface, cadvisorInterface cadvisor.I cm.topologyManager = topologymanager.NewFakeManager() - klog.Infof("Creating device plugin manager: %t", devicePluginEnabled) + klog.InfoS("Creating device plugin manager", "devicePluginEnabled", devicePluginEnabled) if devicePluginEnabled { cm.deviceManager, err = devicemanager.NewManagerImpl(nil, cm.topologyManager) cm.topologyManager.AddHintProvider(cm.deviceManager) diff --git a/pkg/kubelet/cm/cpumanager/fake_cpu_manager.go b/pkg/kubelet/cm/cpumanager/fake_cpu_manager.go index 856d322fae7..2c38b52b374 100644 --- a/pkg/kubelet/cm/cpumanager/fake_cpu_manager.go +++ b/pkg/kubelet/cm/cpumanager/fake_cpu_manager.go @@ -32,7 +32,7 @@ type fakeManager struct { } func (m *fakeManager) Start(activePods ActivePodsFunc, sourcesReady config.SourcesReady, podStatusProvider status.PodStatusProvider, containerRuntime runtimeService, initialContainers containermap.ContainerMap) error { - klog.Info("Start()") + klog.InfoS("Start()") return nil } diff --git a/pkg/kubelet/cm/devicemanager/device_plugin_stub.go b/pkg/kubelet/cm/devicemanager/device_plugin_stub.go index 1d2ce78d3b2..ef1ca4569e6 100644 --- a/pkg/kubelet/cm/devicemanager/device_plugin_stub.go +++ b/pkg/kubelet/cm/devicemanager/device_plugin_stub.go @@ -187,7 +187,7 @@ func (m *Stub) Register(kubeletEndpoint, resourceName string, pluginSockDir stri return nil } } - klog.Info("Deprecation file not found. Invoke registration") + klog.InfoS("Deprecation file not found. Invoke registration") ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) defer cancel() diff --git a/pkg/kubelet/cm/devicemanager/manager.go b/pkg/kubelet/cm/devicemanager/manager.go index c8a26085df5..1708176fc9b 100644 --- a/pkg/kubelet/cm/devicemanager/manager.go +++ b/pkg/kubelet/cm/devicemanager/manager.go @@ -582,7 +582,7 @@ func (m *ManagerImpl) writeCheckpoint() error { err := m.checkpointManager.CreateCheckpoint(kubeletDeviceManagerCheckpoint, data) if err != nil { err2 := fmt.Errorf("failed to write checkpoint file %q: %v", kubeletDeviceManagerCheckpoint, err) - klog.Warning(err2) + klog.InfoS("Failed to write checkpoint file", "err", err) return err2 } return nil @@ -1071,7 +1071,7 @@ func (m *ManagerImpl) GetAllocatableDevices() ResourceDeviceInstances { m.mutex.Lock() resp := m.allDevices.Clone() m.mutex.Unlock() - klog.V(4).Infof("known devices: %d", len(resp)) + klog.V(4).InfoS("known devices", "numDevices", len(resp)) return resp } diff --git a/pkg/kubelet/config/file_unsupported.go b/pkg/kubelet/config/file_unsupported.go index 5b58246763a..7a262f421d9 100644 --- a/pkg/kubelet/config/file_unsupported.go +++ b/pkg/kubelet/config/file_unsupported.go @@ -25,7 +25,7 @@ import ( ) func (s *sourceFile) startWatch() { - klog.Errorf("Watching source file is unsupported in this build") + klog.ErrorS(nil, "Watching source file is unsupported in this build") } func (s *sourceFile) consumeWatchEvent(e *watchEvent) error { diff --git a/pkg/kubelet/kubelet.go b/pkg/kubelet/kubelet.go index 50effbb1550..00646b120b8 100644 --- a/pkg/kubelet/kubelet.go +++ b/pkg/kubelet/kubelet.go @@ -1952,7 +1952,7 @@ func (kl *Kubelet) syncLoopIteration(configCh <-chan kubetypes.PodUpdate, handle klog.V(4).InfoS("SyncLoop RECONCILE", "source", u.Source, "pods", format.Pods(u.Pods)) handler.HandlePodReconcile(u.Pods) case kubetypes.DELETE: - klog.V(2).Infof("SyncLoop DELETE", "source", u.Source, "pods", format.Pods(u.Pods)) + klog.V(2).InfoS("SyncLoop DELETE", "source", u.Source, "pods", format.Pods(u.Pods)) // DELETE is treated as a UPDATE because of graceful deletion. handler.HandlePodUpdates(u.Pods) case kubetypes.SET: @@ -2023,18 +2023,14 @@ func (kl *Kubelet) syncLoopIteration(configCh <-chan kubetypes.PodUpdate, handle } func handleProbeSync(kl *Kubelet, update proberesults.Update, handler SyncHandler, probe, status string) { - probeAndStatus := probe - if len(status) > 0 { - probeAndStatus = fmt.Sprintf("%s (container %s)", probe, status) - } // We should not use the pod from manager, because it is never updated after initialization. pod, ok := kl.podManager.GetPodByUID(update.PodUID) if !ok { // If the pod no longer exists, ignore the update. - klog.V(4).Infof("SyncLoop %s: ignore irrelevant update: %#v", probeAndStatus, update) + klog.V(4).InfoS("SyncLoop (probe): ignore irrelevant update", "probe", probe, "status", status, "update", update) return } - klog.V(1).Infof("SyncLoop %s: %q", probeAndStatus, format.Pod(pod)) + klog.V(1).InfoS("SyncLoop (probe)", "probe", probe, "status", status, "pod", klog.KObj(pod)) handler.HandlePodSyncs([]*v1.Pod{pod}) } @@ -2044,7 +2040,7 @@ func (kl *Kubelet) dispatchWork(pod *v1.Pod, syncType kubetypes.SyncPodType, mir // check whether we are ready to delete the pod from the API server (all status up to date) containersTerminal, podWorkerTerminal := kl.podAndContainersAreTerminal(pod) if pod.DeletionTimestamp != nil && containersTerminal { - klog.V(4).Infof("Pod has completed execution and should be deleted from the API server", "pod", klog.KObj(pod), "syncType", syncType) + klog.V(4).InfoS("Pod has completed execution and should be deleted from the API server", "pod", klog.KObj(pod), "syncType", syncType) kl.statusManager.TerminatePod(pod) return } diff --git a/pkg/kubelet/kubelet_pods.go b/pkg/kubelet/kubelet_pods.go index c893fef3eed..b610b47ff7f 100644 --- a/pkg/kubelet/kubelet_pods.go +++ b/pkg/kubelet/kubelet_pods.go @@ -1259,7 +1259,7 @@ func (pk *podKillerWithChannel) KillPod(podPair *kubecontainer.PodPair) { if apiPodExists && runningPodExists { klog.V(4).InfoS("Api pod and running pod are pending termination", "apiPodUID", podPair.APIPod.UID, "runningPodUID", podPair.RunningPod.ID) } else if apiPodExists { - klog.V(4).Infof("Api pod is pending termination", "podUID", podPair.APIPod.UID) + klog.V(4).InfoS("Api pod is pending termination", "podUID", podPair.APIPod.UID) } else { klog.V(4).InfoS("Running pod is pending termination", "podUID", podPair.RunningPod.ID) } diff --git a/pkg/kubelet/kubelet_volumes.go b/pkg/kubelet/kubelet_volumes.go index 0aa1a153b84..e2b11841f61 100644 --- a/pkg/kubelet/kubelet_volumes.go +++ b/pkg/kubelet/kubelet_volumes.go @@ -67,7 +67,7 @@ func (kl *Kubelet) podVolumesExist(podUID types.UID) bool { return true } if len(volumePaths) > 0 { - klog.V(4).InfoS("Pod found, but volumes are still mounted on disk", "podUID", podUID, "volumePaths", volumePaths) + klog.V(4).InfoS("Pod found, but volumes are still mounted on disk", "podUID", podUID, "paths", volumePaths) return true } @@ -136,7 +136,7 @@ func (kl *Kubelet) cleanupOrphanedPodDirs(pods []*v1.Pod, runningPods []*kubecon orphanVolumeErrors = append(orphanVolumeErrors, fmt.Errorf("orphaned pod %q found, but failed to rmdir() volume at path %v: %v", uid, volumePath, err)) allVolumesCleanedUp = false } else { - klog.Warningf("Cleaned up orphaned volume from pod %q at %s", uid, volumePath) + klog.InfoS("Cleaned up orphaned volume from pod", "podUID", uid, "path", volumePath) } } } @@ -153,7 +153,7 @@ func (kl *Kubelet) cleanupOrphanedPodDirs(pods []*v1.Pod, runningPods []*kubecon orphanVolumeErrors = append(orphanVolumeErrors, fmt.Errorf("orphaned pod %q found, but failed to rmdir() subpath at path %v: %v", uid, subpathVolumePath, err)) allVolumesCleanedUp = false } else { - klog.Warningf("Cleaned up orphaned volume subpath from pod %q at %s", uid, subpathVolumePath) + klog.InfoS("Cleaned up orphaned volume subpath from pod", "podUID", uid, "path", subpathVolumePath) } } } diff --git a/pkg/kubelet/prober/prober.go b/pkg/kubelet/prober/prober.go index b7db6606ff1..f766c132d28 100644 --- a/pkg/kubelet/prober/prober.go +++ b/pkg/kubelet/prober/prober.go @@ -81,7 +81,7 @@ func newProber( func (pb *prober) recordContainerEvent(pod *v1.Pod, container *v1.Container, eventType, reason, message string, args ...interface{}) { ref, err := kubecontainer.GenerateContainerRef(pod, container) if err != nil { - klog.Errorf("Can't make a ref to pod %q, container %v: %v", format.Pod(pod), container.Name, err) + klog.ErrorS(err, "Can't make a ref to pod and container", "pod", klog.KObj(pod), "containerName", container.Name) return } pb.recorder.Eventf(ref, eventType, reason, message, args...) @@ -102,7 +102,7 @@ func (pb *prober) probe(probeType probeType, pod *v1.Pod, status v1.PodStatus, c } if probeSpec == nil { - klog.InfoS("Probe is nil", "probeType", probeType, "pod", klog.KObj(pod), "podUID", pod.UID, "container", container.Name) + klog.InfoS("Probe is nil", "probeType", probeType, "pod", klog.KObj(pod), "podUID", pod.UID, "containerName", container.Name) return results.Success, nil } @@ -110,19 +110,19 @@ func (pb *prober) probe(probeType probeType, pod *v1.Pod, status v1.PodStatus, c if err != nil || (result != probe.Success && result != probe.Warning) { // Probe failed in one way or another. if err != nil { - klog.V(1).ErrorS(err, "Probe errored", "probeType", probeType, "pod", klog.KObj(pod), "podUID", pod.UID, "container", container.Name) + klog.V(1).ErrorS(err, "Probe errored", "probeType", probeType, "pod", klog.KObj(pod), "podUID", pod.UID, "containerName", container.Name) pb.recordContainerEvent(pod, &container, v1.EventTypeWarning, events.ContainerUnhealthy, "%s probe errored: %v", probeType, err) } else { // result != probe.Success - klog.V(1).InfoS("Probe failed", "probeType", probeType, "pod", klog.KObj(pod), "podUID", pod.UID, "container", container.Name, "probeResult", result, "output", output) + klog.V(1).InfoS("Probe failed", "probeType", probeType, "pod", klog.KObj(pod), "podUID", pod.UID, "containerName", container.Name, "probeResult", result, "output", output) pb.recordContainerEvent(pod, &container, v1.EventTypeWarning, events.ContainerUnhealthy, "%s probe failed: %s", probeType, output) } return results.Failure, err } if result == probe.Warning { pb.recordContainerEvent(pod, &container, v1.EventTypeWarning, events.ContainerProbeWarning, "%s probe warning: %s", probeType, output) - klog.V(3).InfoS("Probe succeeded with a warning", "probeType", probeType, "pod", klog.KObj(pod), "podUID", pod.UID, "container", container.Name, "output", output) + klog.V(3).InfoS("Probe succeeded with a warning", "probeType", probeType, "pod", klog.KObj(pod), "podUID", pod.UID, "containerName", container.Name, "output", output) } else { - klog.V(3).InfoS("Probe succeeded", "probeType", probeType, "pod", klog.KObj(pod), "podUID", pod.UID, "container", container.Name) + klog.V(3).InfoS("Probe succeeded", "probeType", probeType, "pod", klog.KObj(pod), "podUID", pod.UID, "containerName", container.Name) } return results.Success, nil } @@ -155,7 +155,7 @@ func buildHeader(headerList []v1.HTTPHeader) http.Header { func (pb *prober) runProbe(probeType probeType, p *v1.Probe, pod *v1.Pod, status v1.PodStatus, container v1.Container, containerID kubecontainer.ContainerID) (probe.Result, string, error) { timeout := time.Duration(p.TimeoutSeconds) * time.Second if p.Exec != nil { - klog.V(4).Infof("Exec-Probe Pod: %v, Container: %v, Command: %v", pod.Name, container.Name, p.Exec.Command) + klog.V(4).InfoS("Exec-Probe runProbe", "pod", klog.KObj(pod), "containerName", container.Name, "execCommand", p.Exec.Command) command := kubecontainer.ExpandContainerCommandOnlyStatic(p.Exec.Command, container.Env) return pb.exec.Probe(pb.newExecInContainer(container, containerID, command, timeout)) } @@ -170,10 +170,10 @@ func (pb *prober) runProbe(probeType probeType, p *v1.Probe, pod *v1.Pod, status return probe.Unknown, "", err } path := p.HTTPGet.Path - klog.V(4).Infof("HTTP-Probe Host: %v://%v, Port: %v, Path: %v", scheme, host, port, path) + klog.V(4).InfoS("HTTP-Probe Host", "scheme", scheme, "host", host, "port", port, "path", path) url := formatURL(scheme, host, port, path) headers := buildHeader(p.HTTPGet.HTTPHeaders) - klog.V(4).Infof("HTTP-Probe Headers: %v", headers) + klog.V(4).InfoS("HTTP-Probe Headers", "headers", headers) switch probeType { case liveness: return pb.livenessHTTP.Probe(url, headers, timeout) @@ -192,10 +192,10 @@ func (pb *prober) runProbe(probeType probeType, p *v1.Probe, pod *v1.Pod, status if host == "" { host = status.PodIP } - klog.V(4).Infof("TCP-Probe Host: %v, Port: %v, Timeout: %v", host, port, timeout) + klog.V(4).InfoS("TCP-Probe Host", "host", host, "port", port, "timeout", timeout) return pb.tcp.Probe(host, port, timeout) } - klog.Warningf("Failed to find probe builder for container: %v", container) + klog.InfoS("Failed to find probe builder for container", "containerName", container.Name) return probe.Unknown, "", fmt.Errorf("missing probe handler for %s:%s", format.Pod(pod), container.Name) } diff --git a/pkg/kubelet/prober/prober_manager.go b/pkg/kubelet/prober/prober_manager.go index 299652bdaa5..af6c723ec08 100644 --- a/pkg/kubelet/prober/prober_manager.go +++ b/pkg/kubelet/prober/prober_manager.go @@ -252,7 +252,7 @@ func (m *manager) UpdatePodStatus(podUID types.UID, podStatus *v1.PodStatus) { select { case w.manualTriggerCh <- struct{}{}: default: // Non-blocking. - klog.Warningf("Failed to trigger a manual run of %s probe", w.probeType.String()) + klog.InfoS("Failed to trigger a manual run", "probe", w.probeType.String()) } } } diff --git a/pkg/kubelet/status/status_manager.go b/pkg/kubelet/status/status_manager.go index 28b086e30a8..fb607ea8f8f 100644 --- a/pkg/kubelet/status/status_manager.go +++ b/pkg/kubelet/status/status_manager.go @@ -555,7 +555,7 @@ func (m *manager) syncPod(uid types.UID, status versionedPodStatus) { // TODO: make me easier to express from client code pod, err := m.kubeClient.CoreV1().Pods(status.podNamespace).Get(context.TODO(), status.podName, metav1.GetOptions{}) if errors.IsNotFound(err) { - klog.V(3).Infof("Pod does not exist on the server", + klog.V(3).InfoS("Pod does not exist on the server", "podUID", uid, "pod", klog.KRef(status.podNamespace, status.podName)) // If the Pod is deleted the status will be cleared in