From af0b4c9031bd26aa5ce6b2ef4fc66cae14e183dc Mon Sep 17 00:00:00 2001 From: JunYang Date: Sat, 13 Feb 2021 07:34:09 +0800 Subject: [PATCH] Structured Logging migration: modify eviction part logs of kubelet. Signed-off-by: JunYang --- pkg/kubelet/eviction/eviction_manager.go | 48 +++++++++---------- pkg/kubelet/eviction/helpers.go | 18 +++---- .../eviction/memory_threshold_notifier.go | 4 +- .../eviction/threshold_notifier_linux.go | 6 +-- .../threshold_notifier_unsupported.go | 2 +- 5 files changed, 39 insertions(+), 39 deletions(-) diff --git a/pkg/kubelet/eviction/eviction_manager.go b/pkg/kubelet/eviction/eviction_manager.go index 415e6dd940e5..db43a652cf0c 100644 --- a/pkg/kubelet/eviction/eviction_manager.go +++ b/pkg/kubelet/eviction/eviction_manager.go @@ -165,7 +165,7 @@ func (m *managerImpl) Admit(attrs *lifecycle.PodAdmitAttributes) lifecycle.PodAd } // reject pods when under memory pressure (if pod is best effort), or if under disk pressure. - klog.Warningf("Failed to admit pod %s - node has conditions: %v", format.Pod(attrs.Pod), m.nodeConditions) + klog.InfoS("Failed to admit pod to node", "pod", klog.KObj(attrs.Pod), "nodeCondition", m.nodeConditions) return lifecycle.PodAdmitResult{ Admit: false, Reason: Reason, @@ -176,7 +176,7 @@ func (m *managerImpl) Admit(attrs *lifecycle.PodAdmitAttributes) lifecycle.PodAd // Start starts the control loop to observe and response to low compute resources. func (m *managerImpl) Start(diskInfoProvider DiskInfoProvider, podFunc ActivePodsFunc, podCleanedUpFunc PodCleanedUpFunc, monitoringInterval time.Duration) { thresholdHandler := func(message string) { - klog.Infof(message) + klog.InfoS(message) m.synchronize(diskInfoProvider, podFunc) } if m.config.KernelMemcgNotification { @@ -184,7 +184,7 @@ func (m *managerImpl) Start(diskInfoProvider DiskInfoProvider, podFunc ActivePod if threshold.Signal == evictionapi.SignalMemoryAvailable || threshold.Signal == evictionapi.SignalAllocatableMemoryAvailable { notifier, err := NewMemoryThresholdNotifier(threshold, m.config.PodCgroupRoot, &CgroupNotifierFactory{}, thresholdHandler) if err != nil { - klog.Warningf("eviction manager: failed to create memory threshold notifier: %v", err) + klog.InfoS("Eviction manager: failed to create memory threshold notifier", "err", err) } else { go notifier.Start() m.thresholdNotifiers = append(m.thresholdNotifiers, notifier) @@ -196,7 +196,7 @@ func (m *managerImpl) Start(diskInfoProvider DiskInfoProvider, podFunc ActivePod go func() { for { if evictedPods := m.synchronize(diskInfoProvider, podFunc); evictedPods != nil { - klog.Infof("eviction manager: pods %s evicted, waiting for pod to be cleaned up", format.Pods(evictedPods)) + klog.InfoS("Eviction manager: pods evicted, waiting for pod to be cleaned up", "pods", format.Pods(evictedPods)) m.waitForPodsCleanup(podCleanedUpFunc, evictedPods) } else { time.Sleep(monitoringInterval) @@ -235,7 +235,7 @@ func (m *managerImpl) synchronize(diskInfoProvider DiskInfoProvider, podFunc Act return nil } - klog.V(3).Infof("eviction manager: synchronize housekeeping") + klog.V(3).InfoS("Eviction manager: synchronize housekeeping") // build the ranking functions (if not yet known) // TODO: have a function in cadvisor that lets us know if global housekeeping has completed if m.dedicatedImageFs == nil { @@ -252,7 +252,7 @@ func (m *managerImpl) synchronize(diskInfoProvider DiskInfoProvider, podFunc Act updateStats := true summary, err := m.summaryProvider.Get(updateStats) if err != nil { - klog.Errorf("eviction manager: failed to get summary stats: %v", err) + klog.ErrorS(err, "Eviction manager: failed to get summary stats") return nil } @@ -260,7 +260,7 @@ func (m *managerImpl) synchronize(diskInfoProvider DiskInfoProvider, podFunc Act m.thresholdsLastUpdated = m.clock.Now() for _, notifier := range m.thresholdNotifiers { if err := notifier.UpdateThreshold(summary); err != nil { - klog.Warningf("eviction manager: failed to update %s: %v", notifier.Description(), err) + klog.InfoS("Eviction manager: failed to update notifier", "notifier", notifier.Description(), "err", err) } } } @@ -287,7 +287,7 @@ func (m *managerImpl) synchronize(diskInfoProvider DiskInfoProvider, podFunc Act // the set of node conditions that are triggered by currently observed thresholds nodeConditions := nodeConditions(thresholds) if len(nodeConditions) > 0 { - klog.V(3).Infof("eviction manager: node conditions - observed: %v", nodeConditions) + klog.V(3).InfoS("Eviction manager: node conditions - observed", "nodeCondition", nodeConditions) } // track when a node condition was last observed @@ -296,7 +296,7 @@ func (m *managerImpl) synchronize(diskInfoProvider DiskInfoProvider, podFunc Act // node conditions report true if it has been observed within the transition period window nodeConditions = nodeConditionsObservedSince(nodeConditionsLastObservedAt, m.config.PressureTransitionPeriod, now) if len(nodeConditions) > 0 { - klog.V(3).Infof("eviction manager: node conditions - transition period not met: %v", nodeConditions) + klog.V(3).InfoS("Eviction manager: node conditions - transition period not met", "nodeCondition", nodeConditions) } // determine the set of thresholds we need to drive eviction behavior (i.e. all grace periods are met) @@ -326,7 +326,7 @@ func (m *managerImpl) synchronize(diskInfoProvider DiskInfoProvider, podFunc Act } if len(thresholds) == 0 { - klog.V(3).Infof("eviction manager: no resources are starved") + klog.V(3).InfoS("Eviction manager: no resources are starved") return nil } @@ -336,36 +336,36 @@ func (m *managerImpl) synchronize(diskInfoProvider DiskInfoProvider, podFunc Act if !foundAny { return nil } - klog.Warningf("eviction manager: attempting to reclaim %v", resourceToReclaim) + klog.InfoS("Eviction manager: attempting to reclaim", "resourceName", resourceToReclaim) // record an event about the resources we are now attempting to reclaim via eviction m.recorder.Eventf(m.nodeRef, v1.EventTypeWarning, "EvictionThresholdMet", "Attempting to reclaim %s", resourceToReclaim) // check if there are node-level resources we can reclaim to reduce pressure before evicting end-user pods. if m.reclaimNodeLevelResources(thresholdToReclaim.Signal, resourceToReclaim) { - klog.Infof("eviction manager: able to reduce %v pressure without evicting pods.", resourceToReclaim) + klog.InfoS("Eviction manager: able to reduce resource pressure without evicting pods.", "resourceName", resourceToReclaim) return nil } - klog.Infof("eviction manager: must evict pod(s) to reclaim %v", resourceToReclaim) + klog.InfoS("Eviction manager: must evict pod(s) to reclaim", "resourceName", resourceToReclaim) // rank the pods for eviction rank, ok := m.signalToRankFunc[thresholdToReclaim.Signal] if !ok { - klog.Errorf("eviction manager: no ranking function for signal %s", thresholdToReclaim.Signal) + klog.ErrorS(nil, "Eviction manager: no ranking function for signal", "threshold", thresholdToReclaim.Signal) return nil } // the only candidates viable for eviction are those pods that had anything running. if len(activePods) == 0 { - klog.Errorf("eviction manager: eviction thresholds have been met, but no pods are active to evict") + klog.ErrorS(nil, "Eviction manager: eviction thresholds have been met, but no pods are active to evict") return nil } // rank the running pods for eviction for the specified resource rank(activePods, statsFunc) - klog.Infof("eviction manager: pods ranked for eviction: %s", format.Pods(activePods)) + klog.InfoS("Eviction manager: pods ranked for eviction", "pods", format.Pods(activePods)) //record age of metrics for met thresholds that we are using for evictions. for _, t := range thresholds { @@ -388,7 +388,7 @@ func (m *managerImpl) synchronize(diskInfoProvider DiskInfoProvider, podFunc Act return []*v1.Pod{pod} } } - klog.Infof("eviction manager: unable to evict any pods from the node") + klog.InfoS("Eviction manager: unable to evict any pods from the node") return nil } @@ -400,7 +400,7 @@ func (m *managerImpl) waitForPodsCleanup(podCleanedUpFunc PodCleanedUpFunc, pods for { select { case <-timeout.C(): - klog.Warningf("eviction manager: timed out waiting for pods %s to be cleaned up", format.Pods(pods)) + klog.InfoS("Eviction manager: timed out waiting for pods to be cleaned up", "pods", format.Pods(pods)) return case <-ticker.C(): for i, pod := range pods { @@ -408,7 +408,7 @@ func (m *managerImpl) waitForPodsCleanup(podCleanedUpFunc PodCleanedUpFunc, pods break } if i == len(pods)-1 { - klog.Infof("eviction manager: pods %s successfully cleaned up", format.Pods(pods)) + klog.InfoS("Eviction manager: pods successfully cleaned up", "pods", format.Pods(pods)) return } } @@ -422,14 +422,14 @@ func (m *managerImpl) reclaimNodeLevelResources(signalToReclaim evictionapi.Sign for _, nodeReclaimFunc := range nodeReclaimFuncs { // attempt to reclaim the pressured resource. if err := nodeReclaimFunc(); err != nil { - klog.Warningf("eviction manager: unexpected error when attempting to reduce %v pressure: %v", resourceToReclaim, err) + klog.InfoS("Eviction manager: unexpected error when attempting to reduce resource pressure", "resourceName", resourceToReclaim, "err", err) } } if len(nodeReclaimFuncs) > 0 { summary, err := m.summaryProvider.Get(true) if err != nil { - klog.Errorf("eviction manager: failed to get summary stats after resource reclaim: %v", err) + klog.ErrorS(err, "Eviction manager: failed to get summary stats after resource reclaim") return false } @@ -557,7 +557,7 @@ func (m *managerImpl) evictPod(pod *v1.Pod, gracePeriodOverride int64, evictMsg // do not evict such pods. Static pods are not re-admitted after evictions. // https://github.com/kubernetes/kubernetes/issues/40573 has more details. if kubelettypes.IsCriticalPod(pod) { - klog.Errorf("eviction manager: cannot evict a critical pod %s", format.Pod(pod)) + klog.ErrorS(nil, "Eviction manager: cannot evict a critical pod", "pod", klog.KObj(pod)) return false } status := v1.PodStatus{ @@ -570,9 +570,9 @@ func (m *managerImpl) evictPod(pod *v1.Pod, gracePeriodOverride int64, evictMsg // this is a blocking call and should only return when the pod and its containers are killed. err := m.killPodFunc(pod, status, &gracePeriodOverride) if err != nil { - klog.Errorf("eviction manager: pod %s failed to evict %v", format.Pod(pod), err) + klog.ErrorS(err, "Eviction manager: pod failed to evict", "pod", klog.KObj(pod)) } else { - klog.Infof("eviction manager: pod %s is evicted successfully", format.Pod(pod)) + klog.InfoS("Eviction manager: pod is evicted successfully", "pod", klog.KObj(pod)) } return true } diff --git a/pkg/kubelet/eviction/helpers.go b/pkg/kubelet/eviction/helpers.go index 3585b6565e90..8807bd3fb050 100644 --- a/pkg/kubelet/eviction/helpers.go +++ b/pkg/kubelet/eviction/helpers.go @@ -102,7 +102,7 @@ func getReclaimableThreshold(thresholds []evictionapi.Threshold) (evictionapi.Th if resourceToReclaim, ok := signalToResource[thresholdToReclaim.Signal]; ok { return thresholdToReclaim, resourceToReclaim, true } - klog.V(3).Infof("eviction manager: threshold %s was crossed, but reclaim is not implemented for this threshold.", thresholdToReclaim.Signal) + klog.V(3).InfoS("Eviction manager: threshold was crossed, but reclaim is not implemented for this threshold.", "threshold", thresholdToReclaim.Signal) } return evictionapi.Threshold{}, "", false } @@ -671,7 +671,7 @@ func makeSignalObservations(summary *statsapi.Summary) (signalObservations, stat } } if allocatableContainer, err := getSysContainer(summary.Node.SystemContainers, statsapi.SystemContainerPods); err != nil { - klog.Errorf("eviction manager: failed to construct signal: %q error: %v", evictionapi.SignalAllocatableMemoryAvailable, err) + klog.ErrorS(err, "Eviction manager: failed to construct signal", "signal", evictionapi.SignalAllocatableMemoryAvailable) } else { if memory := allocatableContainer.Memory; memory != nil && memory.AvailableBytes != nil && memory.WorkingSetBytes != nil { result[evictionapi.SignalAllocatableMemoryAvailable] = signalObservation{ @@ -744,7 +744,7 @@ func thresholdsMet(thresholds []evictionapi.Threshold, observations signalObserv threshold := thresholds[i] observed, found := observations[threshold.Signal] if !found { - klog.Warningf("eviction manager: no observation found for eviction signal %v", threshold.Signal) + klog.InfoS("Eviction manager: no observation found for eviction signal", "signal", threshold.Signal) continue } // determine if we have met the specified threshold @@ -772,9 +772,9 @@ func debugLogObservations(logPrefix string, observations signalObservations) { } for k, v := range observations { if !v.time.IsZero() { - klog.Infof("eviction manager: %v: signal=%v, available: %v, capacity: %v, time: %v", logPrefix, k, v.available, v.capacity, v.time) + klog.InfoS("Eviction manager:", "log", logPrefix, "signal", k, "resourceName", v.available, "capacity", v.capacity, "time", v.time) } else { - klog.Infof("eviction manager: %v: signal=%v, available: %v, capacity: %v", logPrefix, k, v.available, v.capacity) + klog.InfoS("Eviction manager:", "log", logPrefix, "signal", k, "resourceName", v.available, "capacity", v.capacity) } } } @@ -788,9 +788,9 @@ func debugLogThresholdsWithObservation(logPrefix string, thresholds []evictionap observed, found := observations[threshold.Signal] if found { quantity := evictionapi.GetThresholdQuantity(threshold.Value, observed.capacity) - klog.Infof("eviction manager: %v: threshold [signal=%v, quantity=%v] observed %v", logPrefix, threshold.Signal, quantity, observed.available) + klog.InfoS("Eviction manager: threshold observed resource", "log", logPrefix, "signal", threshold.Signal, "quantity", quantity, "resource", observed.available) } else { - klog.Infof("eviction manager: %v: threshold [signal=%v] had no observation", logPrefix, threshold.Signal) + klog.InfoS("Eviction manager: threshold had no observation", "log", logPrefix, "signal", threshold.Signal) } } } @@ -801,7 +801,7 @@ func thresholdsUpdatedStats(thresholds []evictionapi.Threshold, observations, la threshold := thresholds[i] observed, found := observations[threshold.Signal] if !found { - klog.Warningf("eviction manager: no observation found for eviction signal %v", threshold.Signal) + klog.InfoS("Eviction manager: no observation found for eviction signal", "signal", threshold.Signal) continue } last, found := lastObservations[threshold.Signal] @@ -831,7 +831,7 @@ func thresholdsMetGracePeriod(observedAt thresholdsObservedAt, now time.Time) [] for threshold, at := range observedAt { duration := now.Sub(at) if duration < threshold.GracePeriod { - klog.V(2).Infof("eviction manager: eviction criteria not yet met for %v, duration: %v", formatThreshold(threshold), duration) + klog.V(2).InfoS("Eviction manager: eviction criteria not yet met", "threshold", formatThreshold(threshold), "duration", duration) continue } results = append(results, threshold) diff --git a/pkg/kubelet/eviction/memory_threshold_notifier.go b/pkg/kubelet/eviction/memory_threshold_notifier.go index a899c98adcd4..3ce5fb811e14 100644 --- a/pkg/kubelet/eviction/memory_threshold_notifier.go +++ b/pkg/kubelet/eviction/memory_threshold_notifier.go @@ -71,7 +71,7 @@ func NewMemoryThresholdNotifier(threshold evictionapi.Threshold, cgroupRoot stri } func (m *memoryThresholdNotifier) Start() { - klog.Infof("eviction manager: created %s", m.Description()) + klog.InfoS("Eviction manager: created memoryThresholdNotifier", "notifier", m.Description()) for range m.events { m.handler(fmt.Sprintf("eviction manager: %s crossed", m.Description())) } @@ -98,7 +98,7 @@ func (m *memoryThresholdNotifier) UpdateThreshold(summary *statsapi.Summary) err memcgThreshold.Sub(*evictionThresholdQuantity) memcgThreshold.Add(*inactiveFile) - klog.V(3).Infof("eviction manager: setting %s to %s\n", m.Description(), memcgThreshold.String()) + klog.V(3).InfoS("Eviction manager: setting notifier to capacity", "notifier", m.Description(), "capacity", memcgThreshold.String()) if m.notifier != nil { m.notifier.Stop() } diff --git a/pkg/kubelet/eviction/threshold_notifier_linux.go b/pkg/kubelet/eviction/threshold_notifier_linux.go index 270a7452db9f..891bc4d001c9 100644 --- a/pkg/kubelet/eviction/threshold_notifier_linux.go +++ b/pkg/kubelet/eviction/threshold_notifier_linux.go @@ -104,7 +104,7 @@ func (n *linuxCgroupNotifier) Start(eventCh chan<- struct{}) { Events: unix.EPOLLIN, }) if err != nil { - klog.Warningf("eviction manager: error adding epoll eventfd: %v", err) + klog.InfoS("Eviction manager: error adding epoll eventfd", "err", err) return } for { @@ -115,7 +115,7 @@ func (n *linuxCgroupNotifier) Start(eventCh chan<- struct{}) { } event, err := wait(n.epfd, n.eventfd, notifierRefreshInterval) if err != nil { - klog.Warningf("eviction manager: error while waiting for memcg events: %v", err) + klog.InfoS("Eviction manager: error while waiting for memcg events", "err", err) return } else if !event { // Timeout on wait. This is expected if the threshold was not crossed @@ -125,7 +125,7 @@ func (n *linuxCgroupNotifier) Start(eventCh chan<- struct{}) { buf := make([]byte, eventSize) _, err = unix.Read(n.eventfd, buf) if err != nil { - klog.Warningf("eviction manager: error reading memcg events: %v", err) + klog.InfoS("Eviction manager: error reading memcg events", "err", err) return } eventCh <- struct{}{} diff --git a/pkg/kubelet/eviction/threshold_notifier_unsupported.go b/pkg/kubelet/eviction/threshold_notifier_unsupported.go index c82954e25dda..0b334caa0b29 100644 --- a/pkg/kubelet/eviction/threshold_notifier_unsupported.go +++ b/pkg/kubelet/eviction/threshold_notifier_unsupported.go @@ -22,7 +22,7 @@ import "k8s.io/klog/v2" // NewCgroupNotifier creates a cgroup notifier that does nothing because cgroups do not exist on non-linux systems. func NewCgroupNotifier(path, attribute string, threshold int64) (CgroupNotifier, error) { - klog.V(5).Infof("cgroup notifications not supported") + klog.V(5).InfoS("cgroup notifications not supported") return &unsupportedThresholdNotifier{}, nil }