Merge pull request kubernetes#125699 from pohly/scheduler-framework-l…

…ogging

scheduler: fix klog.KObjSlice when applied to []*NodeInfo

pkg/scheduler/framework/types.go

@@ -591,6 +591,21 @@ type NodeInfo struct {
 	Generation int64
 }
 
+// NodeInfo implements KMetadata, so for example klog.KObjSlice(nodes) works
+// when nodes is a []*NodeInfo.
+var _ klog.KMetadata = &NodeInfo{}
+
+func (n *NodeInfo) GetName() string {
+	if n == nil {
+		return "<nil>"
+	}
+	if n.node == nil {
+		return "<no node>"
+	}
+	return n.node.Name
+}
+func (n *NodeInfo) GetNamespace() string { return "" }
+
 // nextGeneration: Let's make sure history never forgets the name...
 // Increments the generation number monotonically ensuring that generation numbers never collide.
 // Collision of the generation numbers would be particularly problematic if a node was deleted and

pkg/scheduler/framework/types_test.go

@@ -19,6 +19,7 @@ package framework
 import (
 	"fmt"
 	"reflect"
+	"strings"
 	"testing"
 
 	"github.com/google/go-cmp/cmp"
@@ -29,9 +30,11 @@ import (
 	"k8s.io/apimachinery/pkg/util/sets"
 	utilfeature "k8s.io/apiserver/pkg/util/feature"
 	featuregatetesting "k8s.io/component-base/featuregate/testing"
+	"k8s.io/klog/v2"
 	"k8s.io/kubernetes/pkg/features"
 	st "k8s.io/kubernetes/pkg/scheduler/testing"
 	"k8s.io/kubernetes/test/utils/ktesting"
+	"k8s.io/kubernetes/test/utils/ktesting/initoption"
 )
 
 func TestNewResource(t *testing.T) {
@@ -1657,3 +1660,17 @@ func TestCloudEvent_Match(t *testing.T) {
 		})
 	}
 }
+
+func TestNodeInfoKMetadata(t *testing.T) {
+	tCtx := ktesting.Init(t, initoption.BufferLogs(true))
+	logger := tCtx.Logger()
+	logger.Info("Some NodeInfo slice", "nodes", klog.KObjSlice([]*NodeInfo{nil, {}, {node: &v1.Node{}}, {node: &v1.Node{ObjectMeta: metav1.ObjectMeta{Name: "worker"}}}}))
+
+	output := logger.GetSink().(ktesting.Underlier).GetBuffer().String()
+
+	// The initial nil entry gets turned into empty ObjectRef by klog,
+	// which becomes an empty string during output formatting.
+	if !strings.Contains(output, `Some NodeInfo slice nodes=["","<no node>","","worker"]`) {
+		tCtx.Fatalf("unexpected output:\n%s", output)
+	}
+}

test/utils/ktesting/initoption/initoption.go

@@ -28,3 +28,13 @@ func PerTestOutput(enabled bool) InitOption {
 		c.PerTestOutput = enabled
 	}
 }
+
+// BufferLogs controls whether log entries are captured in memory in addition
+// to being printed. Off by default. Unit tests that want to verify that
+// log entries are emitted as expected can turn this on and then retrieve
+// the captured log through the Underlier LogSink interface.
+func BufferLogs(enabled bool) InitOption {
+	return func(c *internal.InitConfig) {
+		c.BufferLogs = enabled
+	}
+}

test/utils/ktesting/internal/config.go

@@ -18,4 +18,5 @@ package internal
 
 type InitConfig struct {
 	PerTestOutput bool
+	BufferLogs    bool
 }

test/utils/ktesting/tcontext.go

@@ -36,7 +36,8 @@ import (
 )
 
 // Underlier is the additional interface implemented by the per-test LogSink
-// behind [TContext.Logger].
+// behind [TContext.Logger]. Together with [initoption.BufferLogs] it can be
+// used to capture log output in memory to check it in tests.
 type Underlier = ktesting.Underlier
 
 // CleanupGracePeriod is the time that a [TContext] gets canceled before the
@@ -245,6 +246,7 @@ func Init(tb TB, opts ...InitOption) TContext {
 			}),
 			ktesting.VerbosityFlagName("v"),
 			ktesting.VModuleFlagName("vmodule"),
+			ktesting.BufferLogs(c.BufferLogs),
 		)
 
 		// Copy klog settings instead of making the ktesting logger