From 50d2b246d9ddf10ddad21c0b41444f30c272dd03 Mon Sep 17 00:00:00 2001 From: Ali Farah Date: Sat, 15 Aug 2020 14:46:14 +1000 Subject: [PATCH] Change klog to use structured logging Signed-off-by: Ali Farah --- pkg/descheduler/descheduler.go | 2 +- pkg/descheduler/node/node.go | 8 ++-- pkg/descheduler/strategies/duplicates.go | 8 ++-- .../strategies/lownodeutilization.go | 37 ++++++++++--------- pkg/descheduler/strategies/node_affinity.go | 10 ++--- pkg/descheduler/strategies/node_taint.go | 8 ++-- .../strategies/pod_antiaffinity.go | 6 +-- pkg/descheduler/strategies/pod_lifetime.go | 8 ++-- pkg/descheduler/strategies/toomanyrestarts.go | 8 ++-- pkg/utils/pod.go | 2 +- 10 files changed, 49 insertions(+), 48 deletions(-) diff --git a/pkg/descheduler/descheduler.go b/pkg/descheduler/descheduler.go index 993f3295ea..c94c5faa06 100644 --- a/pkg/descheduler/descheduler.go +++ b/pkg/descheduler/descheduler.go @@ -97,7 +97,7 @@ func RunDeschedulerStrategies(ctx context.Context, rs *options.DeschedulerServer wait.Until(func() { nodes, err := nodeutil.ReadyNodes(ctx, rs.Client, nodeInformer, nodeSelector, stopChannel) if err != nil { - klog.V(1).Infof("Unable to get ready nodes: %v", err) + klog.V(1).InfoS("Unable to get ready nodes", "err", err) close(stopChannel) return } diff --git a/pkg/descheduler/node/node.go b/pkg/descheduler/node/node.go index 604f218fd1..326705e665 100644 --- a/pkg/descheduler/node/node.go +++ b/pkg/descheduler/node/node.go @@ -77,7 +77,7 @@ func IsReady(node *v1.Node) bool { // - NodeOutOfDisk condition status is ConditionFalse, // - NodeNetworkUnavailable condition status is ConditionFalse. if cond.Type == v1.NodeReady && cond.Status != v1.ConditionTrue { - klog.V(1).Infof("Ignoring node %v with %v condition status %v", node.Name, cond.Type, cond.Status) + klog.V(1).InfoS("Ignoring node", "node", klog.KObj(node), "condition", cond.Type, "status", cond.Status) return false } /*else if cond.Type == v1.NodeOutOfDisk && cond.Status != v1.ConditionFalse { klog.V(4).Infof("Ignoring node %v with %v condition status %v", node.Name, cond.Type, cond.Status) @@ -112,7 +112,7 @@ func PodFitsAnyNode(pod *v1.Pod, nodes []*v1.Node) bool { continue } if !IsNodeUnschedulable(node) { - klog.V(2).Infof("Pod %v can possibly be scheduled on %v", pod.Name, node.Name) + klog.V(2).InfoS("Pod can possibly be scheduled on a different node", "pod", klog.KObj(pod), "node", klog.KObj(node)) return true } } @@ -130,10 +130,10 @@ func PodFitsCurrentNode(pod *v1.Pod, node *v1.Node) bool { } if !ok { - klog.V(2).Infof("Pod %v does not fit on node %v", pod.Name, node.Name) + klog.V(2).InfoS("Pod does not fit on node", "pod", klog.KObj(pod), "node", klog.KObj(node)) return false } - klog.V(2).Infof("Pod %v fits on node %v", pod.Name, node.Name) + klog.V(2).InfoS("Pod fits on node", "pod", klog.KObj(pod), "node", klog.KObj(node)) return true } diff --git a/pkg/descheduler/strategies/duplicates.go b/pkg/descheduler/strategies/duplicates.go index 53ba26998a..1c5669928c 100644 --- a/pkg/descheduler/strategies/duplicates.go +++ b/pkg/descheduler/strategies/duplicates.go @@ -63,17 +63,17 @@ func RemoveDuplicatePods( } thresholdPriority, err := utils.GetPriorityFromStrategyParams(ctx, client, strategy.Params) if err != nil { - klog.V(1).Infof("failed to get threshold priority from strategy's params: %#v", err) + klog.V(1).InfoS("Failed to get threshold priority from strategy's params", "err", err) return } evictable := podEvictor.Evictable(evictions.WithPriorityThreshold(thresholdPriority)) for _, node := range nodes { - klog.V(1).Infof("Processing node: %#v", node.Name) + klog.V(1).InfoS("Processing node", "node", klog.KObj(node)) pods, err := podutil.ListPodsOnANode(ctx, client, node, podutil.WithFilter(evictable.IsEvictable)) if err != nil { - klog.Errorf("error listing evictable pods on node %s: %+v", node.Name, err) + klog.ErrorS(err, "Error listing evictable pods on node", "node", klog.KObj(node)) continue } @@ -131,7 +131,7 @@ func RemoveDuplicatePods( for _, pod := range duplicatePods { if _, err := podEvictor.EvictPod(ctx, pod, node, "RemoveDuplicatePods"); err != nil { - klog.Errorf("Error evicting pod: (%#v)", err) + klog.ErrorS(err, "Error evicting pod", "pod", klog.KObj(pod)) break } } diff --git a/pkg/descheduler/strategies/lownodeutilization.go b/pkg/descheduler/strategies/lownodeutilization.go index 7e260881cf..4d608770a7 100644 --- a/pkg/descheduler/strategies/lownodeutilization.go +++ b/pkg/descheduler/strategies/lownodeutilization.go @@ -71,7 +71,7 @@ func LowNodeUtilization(ctx context.Context, client clientset.Interface, strateg } thresholdPriority, err := utils.GetPriorityFromStrategyParams(ctx, client, strategy.Params) if err != nil { - klog.V(1).Infof("failed to get threshold priority from strategy's params: %#v", err) + klog.V(1).InfoS("Failed to get threshold priority from strategy's params", "err", err) return } @@ -113,12 +113,12 @@ func LowNodeUtilization(ctx context.Context, client clientset.Interface, strateg } if len(lowNodes) == len(nodes) { - klog.V(1).Infof("all nodes are underutilized, nothing to do here") + klog.V(1).Infof("All nodes are underutilized, nothing to do here") return } if len(targetNodes) == 0 { - klog.V(1).Infof("all nodes are under target utilization, nothing to do here") + klog.V(1).Infof("All nodes are under target utilization, nothing to do here") return } @@ -136,7 +136,7 @@ func LowNodeUtilization(ctx context.Context, client clientset.Interface, strateg podEvictor, evictable.IsEvictable) - klog.V(1).Infof("Total number of pods evicted: %v", podEvictor.TotalEvicted()) + klog.V(1).InfoS("Total number of pods evicted", "evictedPods", podEvictor.TotalEvicted()) } // validateStrategyConfig checks if the strategy's config is valid @@ -194,13 +194,14 @@ func classifyNodes(npm NodePodsMap, thresholds api.ResourceThresholds, targetThr } // Check if node is underutilized and if we can schedule pods on it. if !nodeutil.IsNodeUnschedulable(node) && isNodeWithLowUtilization(usage, thresholds) { - klog.V(2).Infof("Node %#v is under utilized with usage: %#v", node.Name, usage) + klog.V(2).InfoS("Node is underutilized", "node", klog.KObj(node), "usage", usage) lowNodes = append(lowNodes, nuMap) } else if isNodeAboveTargetUtilization(usage, targetThresholds) { - klog.V(2).Infof("Node %#v is over utilized with usage: %#v", node.Name, usage) + klog.V(2).InfoS("Node is overutilized", "node", klog.KObj(node), "usage", usage) targetNodes = append(targetNodes, nuMap) } else { - klog.V(2).Infof("Node %#v is appropriately utilized with usage: %#v", node.Name, usage) + klog.V(2).InfoS("Node is appropriately utilized", "node", klog.KObj(node), "usage", usage) + } } return lowNodes, targetNodes @@ -241,21 +242,20 @@ func evictPodsFromTargetNodes( totalMem += ((float64(memPercentage) * float64(nodeCapacity.Memory().Value())) / 100) } - klog.V(1).Infof("Total capacity to be moved: CPU:%v, Mem:%v, Pods:%v", totalCPU, totalMem, totalPods) - klog.V(1).Infof("********Number of pods evicted from each node:***********") + klog.V(1).InfoS("Total capacity to be moved", "CPU", totalCPU, "Mem", totalMem, "Pods", totalPods) for _, node := range targetNodes { nodeCapacity := node.node.Status.Capacity if len(node.node.Status.Allocatable) > 0 { nodeCapacity = node.node.Status.Allocatable } - klog.V(3).Infof("evicting pods from node %#v with usage: %#v", node.node.Name, node.usage) + klog.V(3).InfoS("Evicting pods from node", "node", klog.KObj(node.node), "usage", node.usage) nonRemovablePods, removablePods := classifyPods(node.allPods, podFilter) - klog.V(2).Infof("allPods:%v, nonRemovablePods:%v, removablePods:%v", len(node.allPods), len(nonRemovablePods), len(removablePods)) + klog.V(2).Infof("AllPods:%v, nonRemovablePods:%v, removablePods:%v", len(node.allPods), len(nonRemovablePods), len(removablePods)) if len(removablePods) == 0 { - klog.V(1).Infof("no removable pods on node %#v, try next node", node.node.Name) + klog.V(1).InfoS("No removable pods on node, try next node", "node", klog.KObj(node.node)) continue } @@ -263,8 +263,7 @@ func evictPodsFromTargetNodes( // sort the evictable Pods based on priority. This also sorts them based on QoS. If there are multiple pods with same priority, they are sorted based on QoS tiers. podutil.SortPodsBasedOnPriorityLowToHigh(removablePods) evictPods(ctx, removablePods, targetThresholds, nodeCapacity, node.usage, &totalPods, &totalCPU, &totalMem, taintsOfLowNodes, podEvictor, node.node) - - klog.V(1).Infof("%v pods evicted from node %#v with usage %v", podEvictor.NodeEvicted(node.node), node.node.Name, node.usage) + klog.V(1).InfoS("Evicted pods from node", "node", klog.KObj(node.node), "evictedPods", podEvictor.NodeEvicted(node.node), "usage", node.usage) } } @@ -285,7 +284,8 @@ func evictPods( onePodPercentage := api.Percentage((float64(1) * 100) / float64(nodeCapacity.Pods().Value())) for _, pod := range inputPods { if !utils.PodToleratesTaints(pod, taintsOfLowNodes) { - klog.V(3).Infof("Skipping eviction for Pod: %#v, doesn't tolerate node taint", pod.Name) + klog.V(3).InfoS("Skipping eviction for pod, doesn't tolerate node taint", "pod", klog.KObj(pod)) + continue } @@ -294,12 +294,13 @@ func evictPods( success, err := podEvictor.EvictPod(ctx, pod, node, "LowNodeUtilization") if err != nil { - klog.Errorf("Error evicting pod: (%#v)", err) + klog.ErrorS(err, "Error evicting pod", "pod", klog.KObj(pod)) break } if success { - klog.V(3).Infof("Evicted pod: %#v", pod.Name) + klog.V(3).InfoS("Evicted pods", "pod", klog.KObj(pod), "err", err) + // update remaining pods nodeUsage[v1.ResourcePods] -= onePodPercentage *totalPods-- @@ -312,7 +313,7 @@ func evictPods( *totalMem -= float64(mUsage) nodeUsage[v1.ResourceMemory] -= api.Percentage(float64(mUsage) / float64(nodeCapacity.Memory().Value()) * 100) - klog.V(3).Infof("updated node usage: %#v", nodeUsage) + klog.V(3).InfoS("Updated node usage", "updatedUsage", nodeUsage) // check if node utilization drops below target threshold or any required capacity (cpu, memory, pods) is moved if !isNodeAboveTargetUtilization(nodeUsage, targetThresholds) || *totalPods <= 0 || *totalCPU <= 0 || *totalMem <= 0 { break diff --git a/pkg/descheduler/strategies/node_affinity.go b/pkg/descheduler/strategies/node_affinity.go index a17ac191af..1dc95a9835 100644 --- a/pkg/descheduler/strategies/node_affinity.go +++ b/pkg/descheduler/strategies/node_affinity.go @@ -54,7 +54,7 @@ func RemovePodsViolatingNodeAffinity(ctx context.Context, client clientset.Inter } thresholdPriority, err := utils.GetPriorityFromStrategyParams(ctx, client, strategy.Params) if err != nil { - klog.V(1).Infof("failed to get threshold priority from strategy's params: %#v", err) + klog.V(1).InfoS("Failed to get threshold priority from strategy's params", "err", err) return } @@ -67,12 +67,12 @@ func RemovePodsViolatingNodeAffinity(ctx context.Context, client clientset.Inter evictable := podEvictor.Evictable(evictions.WithPriorityThreshold(thresholdPriority)) for _, nodeAffinity := range strategy.Params.NodeAffinityType { - klog.V(2).Infof("Executing for nodeAffinityType: %v", nodeAffinity) + klog.V(2).InfoS("Executing for nodeAffinityType", "nodeAffinity", nodeAffinity) switch nodeAffinity { case "requiredDuringSchedulingIgnoredDuringExecution": for _, node := range nodes { - klog.V(1).Infof("Processing node: %#v\n", node.Name) + klog.V(1).InfoS("Processing node", "node", klog.KObj(node)) pods, err := podutil.ListPodsOnANode( ctx, @@ -92,9 +92,9 @@ func RemovePodsViolatingNodeAffinity(ctx context.Context, client clientset.Inter for _, pod := range pods { if pod.Spec.Affinity != nil && pod.Spec.Affinity.NodeAffinity != nil && pod.Spec.Affinity.NodeAffinity.RequiredDuringSchedulingIgnoredDuringExecution != nil { - klog.V(1).Infof("Evicting pod: %v", pod.Name) + klog.V(1).InfoS("Evicting pod", "pod", klog.KObj(pod)) if _, err := podEvictor.EvictPod(ctx, pod, node, "NodeAffinity"); err != nil { - klog.Errorf("Error evicting pod: (%#v)", err) + klog.ErrorS(err, "Error evicting pod") break } } diff --git a/pkg/descheduler/strategies/node_taint.go b/pkg/descheduler/strategies/node_taint.go index 3d697864ba..4a2b48b5c3 100644 --- a/pkg/descheduler/strategies/node_taint.go +++ b/pkg/descheduler/strategies/node_taint.go @@ -61,14 +61,14 @@ func RemovePodsViolatingNodeTaints(ctx context.Context, client clientset.Interfa thresholdPriority, err := utils.GetPriorityFromStrategyParams(ctx, client, strategy.Params) if err != nil { - klog.V(1).Infof("failed to get threshold priority from strategy's params: %#v", err) + klog.V(1).InfoS("Failed to get threshold priority from strategy's params", "err", err) return } evictable := podEvictor.Evictable(evictions.WithPriorityThreshold(thresholdPriority)) for _, node := range nodes { - klog.V(1).Infof("Processing node: %#v\n", node.Name) + klog.V(1).InfoS("Processing node", "node", klog.KObj(node)) pods, err := podutil.ListPodsOnANode( ctx, client, @@ -88,9 +88,9 @@ func RemovePodsViolatingNodeTaints(ctx context.Context, client clientset.Interfa node.Spec.Taints, func(taint *v1.Taint) bool { return taint.Effect == v1.TaintEffectNoSchedule }, ) { - klog.V(2).Infof("Not all taints with NoSchedule effect are tolerated after update for pod %v on node %v", pods[i].Name, node.Name) + klog.V(2).InfoS("Not all taints with NoSchedule effect are tolerated after update for pod on node", "pod", klog.KObj(pods[i]), "node", klog.KObj(node)) if _, err := podEvictor.EvictPod(ctx, pods[i], node, "NodeTaint"); err != nil { - klog.Errorf("Error evicting pod: (%#v)", err) + klog.ErrorS(err, "Error evicting pod") break } } diff --git a/pkg/descheduler/strategies/pod_antiaffinity.go b/pkg/descheduler/strategies/pod_antiaffinity.go index 8a2a3b072b..473437bcde 100644 --- a/pkg/descheduler/strategies/pod_antiaffinity.go +++ b/pkg/descheduler/strategies/pod_antiaffinity.go @@ -62,14 +62,14 @@ func RemovePodsViolatingInterPodAntiAffinity(ctx context.Context, client clients thresholdPriority, err := utils.GetPriorityFromStrategyParams(ctx, client, strategy.Params) if err != nil { - klog.V(1).Infof("failed to get threshold priority from strategy's params: %#v", err) + klog.V(1).InfoS("Failed to get threshold priority from strategy's params", "err", err) return } evictable := podEvictor.Evictable(evictions.WithPriorityThreshold(thresholdPriority)) for _, node := range nodes { - klog.V(1).Infof("Processing node: %#v\n", node.Name) + klog.V(1).InfoS("Processing node", "node", klog.KObj(node)) pods, err := podutil.ListPodsOnANode( ctx, client, @@ -88,7 +88,7 @@ func RemovePodsViolatingInterPodAntiAffinity(ctx context.Context, client clients if checkPodsWithAntiAffinityExist(pods[i], pods) { success, err := podEvictor.EvictPod(ctx, pods[i], node, "InterPodAntiAffinity") if err != nil { - klog.Errorf("Error evicting pod: (%#v)", err) + klog.ErrorS(err, "Error evicting pod") break } diff --git a/pkg/descheduler/strategies/pod_lifetime.go b/pkg/descheduler/strategies/pod_lifetime.go index 8a984b77d7..9214970d3e 100644 --- a/pkg/descheduler/strategies/pod_lifetime.go +++ b/pkg/descheduler/strategies/pod_lifetime.go @@ -56,7 +56,7 @@ func PodLifeTime(ctx context.Context, client clientset.Interface, strategy api.D thresholdPriority, err := utils.GetPriorityFromStrategyParams(ctx, client, strategy.Params) if err != nil { - klog.V(1).Infof("failed to get threshold priority from strategy's params: %#v", err) + klog.V(1).InfoS("Failed to get threshold priority from strategy's params", "err", err) return } @@ -69,17 +69,17 @@ func PodLifeTime(ctx context.Context, client clientset.Interface, strategy api.D evictable := podEvictor.Evictable(evictions.WithPriorityThreshold(thresholdPriority)) for _, node := range nodes { - klog.V(1).Infof("Processing node: %#v", node.Name) + klog.V(1).InfoS("Processing node", "node", klog.KObj(node)) pods := listOldPodsOnNode(ctx, client, node, includedNamespaces, excludedNamespaces, *strategy.Params.MaxPodLifeTimeSeconds, evictable.IsEvictable) for _, pod := range pods { success, err := podEvictor.EvictPod(ctx, pod, node, "PodLifeTime") if success { - klog.V(1).Infof("Evicted pod: %#v because it was created more than %v seconds ago", pod.Name, *strategy.Params.MaxPodLifeTimeSeconds) + klog.V(1).InfoS("Evicted pod because it exceeded its lifetime", "pod", klog.KObj(pod), "maxPodLifeTime", *strategy.Params.MaxPodLifeTimeSeconds) } if err != nil { - klog.Errorf("Error evicting pod: (%#v)", err) + klog.ErrorS(err, "Error evicting pod", "pod", klog.KObj(pod)) break } } diff --git a/pkg/descheduler/strategies/toomanyrestarts.go b/pkg/descheduler/strategies/toomanyrestarts.go index 94e620f54b..9c7443add6 100644 --- a/pkg/descheduler/strategies/toomanyrestarts.go +++ b/pkg/descheduler/strategies/toomanyrestarts.go @@ -57,7 +57,7 @@ func RemovePodsHavingTooManyRestarts(ctx context.Context, client clientset.Inter thresholdPriority, err := utils.GetPriorityFromStrategyParams(ctx, client, strategy.Params) if err != nil { - klog.V(1).Infof("failed to get threshold priority from strategy's params: %#v", err) + klog.V(1).InfoS("Failed to get threshold priority from strategy's params", "err", err) return } @@ -70,7 +70,7 @@ func RemovePodsHavingTooManyRestarts(ctx context.Context, client clientset.Inter evictable := podEvictor.Evictable(evictions.WithPriorityThreshold(thresholdPriority)) for _, node := range nodes { - klog.V(1).Infof("Processing node: %s", node.Name) + klog.V(1).InfoS("Processing node", "node", klog.KObj(node)) pods, err := podutil.ListPodsOnANode( ctx, client, @@ -80,7 +80,7 @@ func RemovePodsHavingTooManyRestarts(ctx context.Context, client clientset.Inter podutil.WithoutNamespaces(excludedNamespaces), ) if err != nil { - klog.Errorf("Error when list pods at node %s", node.Name) + klog.ErrorS(err, "Error listing a nodes pods", "node", klog.KObj(node)) continue } @@ -94,7 +94,7 @@ func RemovePodsHavingTooManyRestarts(ctx context.Context, client clientset.Inter continue } if _, err := podEvictor.EvictPod(ctx, pods[i], node, "TooManyRestarts"); err != nil { - klog.Errorf("Error evicting pod: (%#v)", err) + klog.ErrorS(err, "Error evicting pod", "pod", klog.KObj(pod)) break } } diff --git a/pkg/utils/pod.go b/pkg/utils/pod.go index 011181ea2c..4ea72b0ca1 100644 --- a/pkg/utils/pod.go +++ b/pkg/utils/pod.go @@ -186,7 +186,7 @@ func PodToleratesTaints(pod *v1.Pod, taintsOfNodes map[string][]v1.Taint) bool { if len(pod.Spec.Tolerations) >= len(taintsForNode) && TolerationsTolerateTaintsWithFilter(pod.Spec.Tolerations, taintsForNode, nil) { return true } - klog.V(5).Infof("pod: %#v doesn't tolerate node %s's taints", pod.Name, nodeName) + klog.V(5).InfoS("Pod doesn't tolerate nodes taint", "pod", klog.KObj(pod), "nodeName", nodeName) } return false