From 0f4d0660a7674f816d4f60791b1cfe191fab7050 Mon Sep 17 00:00:00 2001
From: Patrick Ohly <patrick.ohly@intel.com>
Date: Tue, 25 Jan 2022 15:36:54 +0100
Subject: [PATCH] kube-scheduler: finish conversion to structured logging

Thanks to support for multi-line string values we can now also convert
these remaining klog.Info calls without making the output unreadable
in text format.

The debug log messages intentionally don't get changed to ensure that
developers looking for it still find it.

The output now looks like this:

I0322 11:44:46.715093  458409 configfile.go:96] "Using component config" config=<
	apiVersion: kubescheduler.config.k8s.io/v1beta2
	clientConnection:
	  acceptContentTypes: ""
	  burst: 100
	  contentType: application/vnd.kubernetes.protobuf
	  kubeconfig: /var/run/kubernetes/scheduler.kubeconfig
	  qps: 50
	enableContentionProfiling: true
 ...
	  schedulerName: default-scheduler
 >

I0322 11:45:08.695649  458409 comparer.go:42] "Cache comparer started"
I0322 11:45:08.695718  458409 comparer.go:67] "Cache comparer finished"
I0322 11:45:08.695820  458409 dumper.go:52] "Dump of cached NodeInfo" nodes=<
	Node name: 127.0.0.1
	Deleted: false
	Requested Resources: &{MilliCPU:0 Memory:0 EphemeralStorage:0 AllowedPodNumber:0 ScalarResources:map[]}
	Allocatable Resources:&{MilliCPU:36000 Memory:67019448320 EphemeralStorage:181555660500 AllowedPodNumber:110 ScalarResources:map[hugepages-1Gi:0 hugepages-2Mi:0]}
	Scheduled Pods(number: 0):
 >
I0322 11:45:08.695873  458409 dumper.go:62] "Dump of scheduling queue" pods=<
	name: coredns-6874cd75d4-fv6hv, namespace: kube-system, uid: f1df106f-7fd9-460d-8403-333df61b2751, phase: Pending, nominated node:
 >
---
 cmd/kube-scheduler/app/options/configfile.go    |  2 +-
 pkg/scheduler/internal/cache/debugger/dumper.go | 10 ++++++----
 2 files changed, 7 insertions(+), 5 deletions(-)

diff --git a/cmd/kube-scheduler/app/options/configfile.go b/cmd/kube-scheduler/app/options/configfile.go
index 7c115ee8cc8e..84802da767fa 100644
--- a/cmd/kube-scheduler/app/options/configfile.go
+++ b/cmd/kube-scheduler/app/options/configfile.go
@@ -93,7 +93,7 @@ func LogOrWriteConfig(fileName string, cfg *config.KubeSchedulerConfiguration, c
 	}
 
 	if klogV.Enabled() {
-		klogV.Info("Using component config", "\n-------------------------Configuration File Contents Start Here---------------------- \n", buf.String(), "\n------------------------------------Configuration File Contents End Here---------------------------------\n")
+		klogV.InfoS("Using component config", "config", buf.String())
 	}
 
 	if len(fileName) > 0 {
diff --git a/pkg/scheduler/internal/cache/debugger/dumper.go b/pkg/scheduler/internal/cache/debugger/dumper.go
index 0d808c595e6b..b2424b67888c 100644
--- a/pkg/scheduler/internal/cache/debugger/dumper.go
+++ b/pkg/scheduler/internal/cache/debugger/dumper.go
@@ -44,10 +44,12 @@ func (d *CacheDumper) DumpAll() {
 // dumpNodes writes NodeInfo to the scheduler logs.
 func (d *CacheDumper) dumpNodes() {
 	dump := d.cache.Dump()
-	klog.InfoS("Dump of cached NodeInfo")
+	nodeInfos := make([]string, 0, len(dump.Nodes))
 	for name, nodeInfo := range dump.Nodes {
-		klog.Info(d.printNodeInfo(name, nodeInfo))
+		nodeInfos = append(nodeInfos, d.printNodeInfo(name, nodeInfo))
 	}
+	// Extra blank line added between node entries for readability.
+	klog.InfoS("Dump of cached NodeInfo", "nodes", strings.Join(nodeInfos, "\n\n"))
 }
 
 // dumpSchedulingQueue writes pods in the scheduling queue to the scheduler logs.
@@ -57,13 +59,13 @@ func (d *CacheDumper) dumpSchedulingQueue() {
 	for _, p := range pendingPods {
 		podData.WriteString(printPod(p))
 	}
-	klog.Infof("Dump of scheduling queue:\n%s", podData.String())
+	klog.InfoS("Dump of scheduling queue", "pods", podData.String())
 }
 
 // printNodeInfo writes parts of NodeInfo to a string.
 func (d *CacheDumper) printNodeInfo(name string, n *framework.NodeInfo) string {
 	var nodeData strings.Builder
-	nodeData.WriteString(fmt.Sprintf("\nNode name: %s\nDeleted: %t\nRequested Resources: %+v\nAllocatable Resources:%+v\nScheduled Pods(number: %v):\n",
+	nodeData.WriteString(fmt.Sprintf("Node name: %s\nDeleted: %t\nRequested Resources: %+v\nAllocatable Resources:%+v\nScheduled Pods(number: %v):\n",
 		name, n.Node() == nil, n.Requested, n.Allocatable, len(n.Pods)))
 	// Dumping Pod Info
 	for _, p := range n.Pods {