scheduler: update the scheduler interface and cache methods to use contextual logging

pkg/scheduler/eventhandlers.go

@@ -43,9 +43,10 @@ import (
 )
 
 func (sched *Scheduler) onStorageClassAdd(obj interface{}) {
+	logger := sched.logger
 	sc, ok := obj.(*storagev1.StorageClass)
 	if !ok {
-		klog.ErrorS(nil, "Cannot convert to *storagev1.StorageClass", "obj", obj)
+		logger.Error(nil, "Cannot convert to *storagev1.StorageClass", "obj", obj)
 		return
 	}
 
@@ -56,42 +57,45 @@ func (sched *Scheduler) onStorageClassAdd(obj interface{}) {
 	// We don't need to invalidate cached results because results will not be
 	// cached for pod that has unbound immediate PVCs.
 	if sc.VolumeBindingMode != nil && *sc.VolumeBindingMode == storagev1.VolumeBindingWaitForFirstConsumer {
-		sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(queue.StorageClassAdd, nil)
+		sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, queue.StorageClassAdd, nil)
 	}
 }
 
 func (sched *Scheduler) addNodeToCache(obj interface{}) {
+	logger := sched.logger
 	node, ok := obj.(*v1.Node)
 	if !ok {
-		klog.ErrorS(nil, "Cannot convert to *v1.Node", "obj", obj)
+		logger.Error(nil, "Cannot convert to *v1.Node", "obj", obj)
 		return
 	}
 
-	nodeInfo := sched.Cache.AddNode(node)
+	nodeInfo := sched.Cache.AddNode(logger, node)
-	klog.V(3).InfoS("Add event for node", "node", klog.KObj(node))
+	logger.V(3).Info("Add event for node", "node", klog.KObj(node))
-	sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(queue.NodeAdd, preCheckForNode(nodeInfo))
+	sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, queue.NodeAdd, preCheckForNode(nodeInfo))
 }
 
 func (sched *Scheduler) updateNodeInCache(oldObj, newObj interface{}) {
+	logger := sched.logger
 	oldNode, ok := oldObj.(*v1.Node)
 	if !ok {
-		klog.ErrorS(nil, "Cannot convert oldObj to *v1.Node", "oldObj", oldObj)
+		logger.Error(nil, "Cannot convert oldObj to *v1.Node", "oldObj", oldObj)
 		return
 	}
 	newNode, ok := newObj.(*v1.Node)
 	if !ok {
-		klog.ErrorS(nil, "Cannot convert newObj to *v1.Node", "newObj", newObj)
+		logger.Error(nil, "Cannot convert newObj to *v1.Node", "newObj", newObj)
 		return
 	}
 
-	nodeInfo := sched.Cache.UpdateNode(oldNode, newNode)
+	nodeInfo := sched.Cache.UpdateNode(logger, oldNode, newNode)
 	// Only requeue unschedulable pods if the node became more schedulable.
 	if event := nodeSchedulingPropertiesChange(newNode, oldNode); event != nil {
-		sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(*event, preCheckForNode(nodeInfo))
+		sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, *event, preCheckForNode(nodeInfo))
 	}
 }
 
 func (sched *Scheduler) deleteNodeFromCache(obj interface{}) {
+	logger := sched.logger
 	var node *v1.Node
 	switch t := obj.(type) {
 	case *v1.Node:
@@ -100,28 +104,30 @@ func (sched *Scheduler) deleteNodeFromCache(obj interface{}) {
 		var ok bool
 		node, ok = t.Obj.(*v1.Node)
 		if !ok {
-			klog.ErrorS(nil, "Cannot convert to *v1.Node", "obj", t.Obj)
+			logger.Error(nil, "Cannot convert to *v1.Node", "obj", t.Obj)
 			return
 		}
 	default:
-		klog.ErrorS(nil, "Cannot convert to *v1.Node", "obj", t)
+		logger.Error(nil, "Cannot convert to *v1.Node", "obj", t)
 		return
 	}
-	klog.V(3).InfoS("Delete event for node", "node", klog.KObj(node))
+	logger.V(3).Info("Delete event for node", "node", klog.KObj(node))
-	if err := sched.Cache.RemoveNode(node); err != nil {
+	if err := sched.Cache.RemoveNode(logger, node); err != nil {
-		klog.ErrorS(err, "Scheduler cache RemoveNode failed")
+		logger.Error(err, "Scheduler cache RemoveNode failed")
 	}
 }
 
 func (sched *Scheduler) addPodToSchedulingQueue(obj interface{}) {
+	logger := sched.logger
 	pod := obj.(*v1.Pod)
-	klog.V(3).InfoS("Add event for unscheduled pod", "pod", klog.KObj(pod))
+	logger.V(3).Info("Add event for unscheduled pod", "pod", klog.KObj(pod))
-	if err := sched.SchedulingQueue.Add(pod); err != nil {
+	if err := sched.SchedulingQueue.Add(logger, pod); err != nil {
 		utilruntime.HandleError(fmt.Errorf("unable to queue %T: %v", obj, err))
 	}
 }
 
 func (sched *Scheduler) updatePodInSchedulingQueue(oldObj, newObj interface{}) {
+	logger := sched.logger
 	oldPod, newPod := oldObj.(*v1.Pod), newObj.(*v1.Pod)
 	// Bypass update event that carries identical objects; otherwise, a duplicated
 	// Pod may go through scheduling and cause unexpected behavior (see #96071).
@@ -137,12 +143,13 @@ func (sched *Scheduler) updatePodInSchedulingQueue(oldObj, newObj interface{}) {
 		return
 	}
 
-	if err := sched.SchedulingQueue.Update(oldPod, newPod); err != nil {
+	if err := sched.SchedulingQueue.Update(logger, oldPod, newPod); err != nil {
 		utilruntime.HandleError(fmt.Errorf("unable to update %T: %v", newObj, err))
 	}
 }
 
 func (sched *Scheduler) deletePodFromSchedulingQueue(obj interface{}) {
+	logger := sched.logger
 	var pod *v1.Pod
 	switch t := obj.(type) {
 	case *v1.Pod:
@@ -158,7 +165,7 @@ func (sched *Scheduler) deletePodFromSchedulingQueue(obj interface{}) {
 		utilruntime.HandleError(fmt.Errorf("unable to handle object in %T: %T", sched, obj))
 		return
 	}
-	klog.V(3).InfoS("Delete event for unscheduled pod", "pod", klog.KObj(pod))
+	logger.V(3).Info("Delete event for unscheduled pod", "pod", klog.KObj(pod))
 	if err := sched.SchedulingQueue.Delete(pod); err != nil {
 		utilruntime.HandleError(fmt.Errorf("unable to dequeue %T: %v", obj, err))
 	}
@@ -166,53 +173,56 @@ func (sched *Scheduler) deletePodFromSchedulingQueue(obj interface{}) {
 	if err != nil {
 		// This shouldn't happen, because we only accept for scheduling the pods
 		// which specify a scheduler name that matches one of the profiles.
-		klog.ErrorS(err, "Unable to get profile", "pod", klog.KObj(pod))
+		logger.Error(err, "Unable to get profile", "pod", klog.KObj(pod))
 		return
 	}
 	// If a waiting pod is rejected, it indicates it's previously assumed and we're
 	// removing it from the scheduler cache. In this case, signal a AssignedPodDelete
 	// event to immediately retry some unscheduled Pods.
 	if fwk.RejectWaitingPod(pod.UID) {
-		sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(queue.AssignedPodDelete, nil)
+		sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, queue.AssignedPodDelete, nil)
 	}
 }
 
 func (sched *Scheduler) addPodToCache(obj interface{}) {
+	logger := sched.logger
 	pod, ok := obj.(*v1.Pod)
 	if !ok {
-		klog.ErrorS(nil, "Cannot convert to *v1.Pod", "obj", obj)
+		logger.Error(nil, "Cannot convert to *v1.Pod", "obj", obj)
 		return
 	}
-	klog.V(3).InfoS("Add event for scheduled pod", "pod", klog.KObj(pod))
+	logger.V(3).Info("Add event for scheduled pod", "pod", klog.KObj(pod))
 
-	if err := sched.Cache.AddPod(pod); err != nil {
+	if err := sched.Cache.AddPod(logger, pod); err != nil {
-		klog.ErrorS(err, "Scheduler cache AddPod failed", "pod", klog.KObj(pod))
+		logger.Error(err, "Scheduler cache AddPod failed", "pod", klog.KObj(pod))
 	}
 
-	sched.SchedulingQueue.AssignedPodAdded(pod)
+	sched.SchedulingQueue.AssignedPodAdded(logger, pod)
 }
 
 func (sched *Scheduler) updatePodInCache(oldObj, newObj interface{}) {
+	logger := sched.logger
 	oldPod, ok := oldObj.(*v1.Pod)
 	if !ok {
-		klog.ErrorS(nil, "Cannot convert oldObj to *v1.Pod", "oldObj", oldObj)
+		logger.Error(nil, "Cannot convert oldObj to *v1.Pod", "oldObj", oldObj)
 		return
 	}
 	newPod, ok := newObj.(*v1.Pod)
 	if !ok {
-		klog.ErrorS(nil, "Cannot convert newObj to *v1.Pod", "newObj", newObj)
+		logger.Error(nil, "Cannot convert newObj to *v1.Pod", "newObj", newObj)
 		return
 	}
-	klog.V(4).InfoS("Update event for scheduled pod", "pod", klog.KObj(oldPod))
+	logger.V(4).Info("Update event for scheduled pod", "pod", klog.KObj(oldPod))
 
-	if err := sched.Cache.UpdatePod(oldPod, newPod); err != nil {
+	if err := sched.Cache.UpdatePod(logger, oldPod, newPod); err != nil {
-		klog.ErrorS(err, "Scheduler cache UpdatePod failed", "pod", klog.KObj(oldPod))
+		logger.Error(err, "Scheduler cache UpdatePod failed", "pod", klog.KObj(oldPod))
 	}
 
-	sched.SchedulingQueue.AssignedPodUpdated(newPod)
+	sched.SchedulingQueue.AssignedPodUpdated(logger, newPod)
 }
 
 func (sched *Scheduler) deletePodFromCache(obj interface{}) {
+	logger := sched.logger
 	var pod *v1.Pod
 	switch t := obj.(type) {
 	case *v1.Pod:
@@ -221,19 +231,19 @@ func (sched *Scheduler) deletePodFromCache(obj interface{}) {
 		var ok bool
 		pod, ok = t.Obj.(*v1.Pod)
 		if !ok {
-			klog.ErrorS(nil, "Cannot convert to *v1.Pod", "obj", t.Obj)
+			logger.Error(nil, "Cannot convert to *v1.Pod", "obj", t.Obj)
 			return
 		}
 	default:
-		klog.ErrorS(nil, "Cannot convert to *v1.Pod", "obj", t)
+		logger.Error(nil, "Cannot convert to *v1.Pod", "obj", t)
 		return
 	}
-	klog.V(3).InfoS("Delete event for scheduled pod", "pod", klog.KObj(pod))
+	logger.V(3).Info("Delete event for scheduled pod", "pod", klog.KObj(pod))
-	if err := sched.Cache.RemovePod(pod); err != nil {
+	if err := sched.Cache.RemovePod(logger, pod); err != nil {
-		klog.ErrorS(err, "Scheduler cache RemovePod failed", "pod", klog.KObj(pod))
+		logger.Error(err, "Scheduler cache RemovePod failed", "pod", klog.KObj(pod))
 	}
 
-	sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(queue.AssignedPodDelete, nil)
+	sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, queue.AssignedPodDelete, nil)
 }
 
 // assignedPod selects pods that are assigned (scheduled and running).
@@ -317,24 +327,25 @@ func addAllEventHandlers(
 		},
 	)
 
+	logger := sched.logger
 	buildEvtResHandler := func(at framework.ActionType, gvk framework.GVK, shortGVK string) cache.ResourceEventHandlerFuncs {
 		funcs := cache.ResourceEventHandlerFuncs{}
 		if at&framework.Add != 0 {
 			evt := framework.ClusterEvent{Resource: gvk, ActionType: framework.Add, Label: fmt.Sprintf("%vAdd", shortGVK)}
 			funcs.AddFunc = func(_ interface{}) {
-				sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(evt, nil)
+				sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, evt, nil)
 			}
 		}
 		if at&framework.Update != 0 {
 			evt := framework.ClusterEvent{Resource: gvk, ActionType: framework.Update, Label: fmt.Sprintf("%vUpdate", shortGVK)}
 			funcs.UpdateFunc = func(_, _ interface{}) {
-				sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(evt, nil)
+				sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, evt, nil)
 			}
 		}
 		if at&framework.Delete != 0 {
 			evt := framework.ClusterEvent{Resource: gvk, ActionType: framework.Delete, Label: fmt.Sprintf("%vDelete", shortGVK)}
 			funcs.DeleteFunc = func(_ interface{}) {
-				sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(evt, nil)
+				sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, evt, nil)
 			}
 		}
 		return funcs
@@ -402,7 +413,7 @@ func addAllEventHandlers(
 				informerFactory.Storage().V1().StorageClasses().Informer().AddEventHandler(
 					cache.ResourceEventHandlerFuncs{
 						UpdateFunc: func(_, _ interface{}) {
-							sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(queue.StorageClassUpdate, nil)
+							sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, queue.StorageClassUpdate, nil)
 						},
 					},
 				)
@@ -421,7 +432,7 @@ func addAllEventHandlers(
 			// - foos.v1 (2 sections)
 			// - foo.v1.example.com (the first section should be plural)
 			if strings.Count(string(gvk), ".") < 2 {
-				klog.ErrorS(nil, "incorrect event registration", "gvk", gvk)
+				logger.Error(nil, "incorrect event registration", "gvk", gvk)
 				continue
 			}
 			// Fall back to try dynamic informers.

pkg/scheduler/eventhandlers_test.go

@@ -29,6 +29,7 @@ import (
 	storagev1 "k8s.io/api/storage/v1"
 	"k8s.io/apimachinery/pkg/api/resource"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
+	"k8s.io/klog/v2/ktesting"
 
 	"k8s.io/apimachinery/pkg/runtime"
 	"k8s.io/apimachinery/pkg/runtime/schema"
@@ -220,11 +221,13 @@ func TestUpdatePodInCache(t *testing.T) {
 	}
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 			sched := &Scheduler{
-				Cache:           cache.New(ttl, ctx.Done()),
+				Cache:           cache.New(ctx, ttl),
 				SchedulingQueue: queue.NewTestQueue(ctx, nil),
+				logger:          logger,
 			}
 			sched.addPodToCache(tt.oldObj)
 			sched.updatePodInCache(tt.oldObj, tt.newObj)
@@ -430,7 +433,8 @@ func TestAddAllEventHandlers(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 
 			informerFactory := informers.NewSharedInformerFactory(fake.NewSimpleClientset(), 0)
@@ -438,6 +442,7 @@ func TestAddAllEventHandlers(t *testing.T) {
 			testSched := Scheduler{
 				StopEverything:  ctx.Done(),
 				SchedulingQueue: schedulingQueue,
+				logger:          logger,
 			}
 
 			dynclient := dyfake.NewSimpleDynamicClient(scheme)

pkg/scheduler/extender_test.go

@@ -283,9 +283,9 @@ func TestSchedulerWithExtenders(t *testing.T) {
 			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 
-			cache := internalcache.New(time.Duration(0), ctx.Done())
+			cache := internalcache.New(ctx, time.Duration(0))
 			for _, name := range test.nodes {
-				cache.AddNode(createNode(name))
+				cache.AddNode(logger, createNode(name))
 			}
 			fwk, err := st.NewFramework(
 				ctx,
@@ -304,6 +304,7 @@ func TestSchedulerWithExtenders(t *testing.T) {
 				nodeInfoSnapshot:         emptySnapshot,
 				percentageOfNodesToScore: schedulerapi.DefaultPercentageOfNodesToScore,
 				Extenders:                extenders,
+				logger:                   logger,
 			}
 			sched.applyDefaultHandlers()
 

pkg/scheduler/framework/interface.go

@@ -35,6 +35,7 @@ import (
 	clientset "k8s.io/client-go/kubernetes"
 	restclient "k8s.io/client-go/rest"
 	"k8s.io/client-go/tools/events"
+	"k8s.io/klog/v2"
 	"k8s.io/kubernetes/pkg/scheduler/apis/config"
 	"k8s.io/kubernetes/pkg/scheduler/framework/parallelize"
 )
@@ -704,11 +705,11 @@ func (ni *NominatingInfo) Mode() NominatingMode {
 type PodNominator interface {
 	// AddNominatedPod adds the given pod to the nominator or
 	// updates it if it already exists.
-	AddNominatedPod(pod *PodInfo, nominatingInfo *NominatingInfo)
+	AddNominatedPod(logger klog.Logger, pod *PodInfo, nominatingInfo *NominatingInfo)
 	// DeleteNominatedPodIfExists deletes nominatedPod from internal cache. It's a no-op if it doesn't exist.
 	DeleteNominatedPodIfExists(pod *v1.Pod)
 	// UpdateNominatedPod updates the <oldPod> with <newPod>.
-	UpdateNominatedPod(oldPod *v1.Pod, newPodInfo *PodInfo)
+	UpdateNominatedPod(logger klog.Logger, oldPod *v1.Pod, newPodInfo *PodInfo)
 	// NominatedPodsForNode returns nominatedPods on the given node.
 	NominatedPodsForNode(nodeName string) []*PodInfo
 }

pkg/scheduler/framework/plugins/defaultpreemption/default_preemption_test.go

@@ -1701,9 +1701,9 @@ func TestPreempt(t *testing.T) {
 			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 
-			cache := internalcache.New(time.Duration(0), ctx.Done())
+			cache := internalcache.New(ctx, time.Duration(0))
 			for _, pod := range test.pods {
-				cache.AddPod(pod)
+				cache.AddPod(logger, pod)
 			}
 			cachedNodeInfoMap := map[string]*framework.NodeInfo{}
 			nodes := make([]*v1.Node, len(test.nodeNames))
@@ -1716,7 +1716,7 @@ func TestPreempt(t *testing.T) {
 					node.ObjectMeta.Labels[labelKeys[i]] = label
 				}
 				node.Name = node.ObjectMeta.Labels["hostname"]
-				cache.AddNode(node)
+				cache.AddNode(logger, node)
 				nodes[i] = node
 
 				// Set nodeInfo to extenders to mock extenders' cache for preemption.

pkg/scheduler/framework/runtime/framework_test.go

@@ -2342,6 +2342,7 @@ func TestFilterPluginsWithNominatedPods(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
+			logger, _ := ktesting.NewTestContext(t)
 			registry := Registry{}
 			cfgPls := &config.Plugins{}
 
@@ -2373,6 +2374,7 @@ func TestFilterPluginsWithNominatedPods(t *testing.T) {
 			podNominator := internalqueue.NewPodNominator(nil)
 			if tt.nominatedPod != nil {
 				podNominator.AddNominatedPod(
+					logger,
 					mustNewPodInfo(t, tt.nominatedPod),
 					&framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: nodeName})
 			}

pkg/scheduler/internal/cache/cache.go

@@ -17,6 +17,7 @@ limitations under the License.
 package cache
 
 import (
+	"context"
 	"fmt"
 	"sync"
 	"time"
@@ -35,11 +36,12 @@ var (
 
 // New returns a Cache implementation.
 // It automatically starts a go routine that manages expiration of assumed pods.
-// "ttl" is how long the assumed pod will get expired, "0" means pod will never expire.
+// "ttl" is how long the assumed pod will get expired.
-// "stop" is the channel that would close the background goroutine.
+// "ctx" is the context that would close the background goroutine.
-func New(ttl time.Duration, stop <-chan struct{}) Cache {
+func New(ctx context.Context, ttl time.Duration) Cache {
-	cache := newCache(ttl, cleanAssumedPeriod, stop)
+	logger := klog.FromContext(ctx)
-	cache.run()
+	cache := newCache(ctx, ttl, cleanAssumedPeriod)
+	cache.run(logger)
 	return cache
 }
 
@@ -97,14 +99,15 @@ func (cache *cacheImpl) createImageStateSummary(state *imageState) *framework.Im
 	}
 }
 
-func newCache(ttl, period time.Duration, stop <-chan struct{}) *cacheImpl {
+func newCache(ctx context.Context, ttl, period time.Duration) *cacheImpl {
+	logger := klog.FromContext(ctx)
 	return &cacheImpl{
 		ttl:    ttl,
 		period: period,
-		stop:   stop,
+		stop:   ctx.Done(),
 
 		nodes:       make(map[string]*nodeInfoListItem),
-		nodeTree:    newNodeTree(nil),
+		nodeTree:    newNodeTree(logger, nil),
 		assumedPods: sets.New[string](),
 		podStates:   make(map[string]*podState),
 		imageStates: make(map[string]*imageState),
@@ -121,10 +124,10 @@ func newNodeInfoListItem(ni *framework.NodeInfo) *nodeInfoListItem {
 // moveNodeInfoToHead moves a NodeInfo to the head of "cache.nodes" doubly
 // linked list. The head is the most recently updated NodeInfo.
 // We assume cache lock is already acquired.
-func (cache *cacheImpl) moveNodeInfoToHead(name string) {
+func (cache *cacheImpl) moveNodeInfoToHead(logger klog.Logger, name string) {
 	ni, ok := cache.nodes[name]
 	if !ok {
-		klog.ErrorS(nil, "No node info with given name found in the cache", "node", klog.KRef("", name))
+		logger.Error(nil, "No node info with given name found in the cache", "node", klog.KRef("", name))
 		return
 	}
 	// if the node info list item is already at the head, we are done.
@@ -149,10 +152,10 @@ func (cache *cacheImpl) moveNodeInfoToHead(name string) {
 // removeNodeInfoFromList removes a NodeInfo from the "cache.nodes" doubly
 // linked list.
 // We assume cache lock is already acquired.
-func (cache *cacheImpl) removeNodeInfoFromList(name string) {
+func (cache *cacheImpl) removeNodeInfoFromList(logger klog.Logger, name string) {
 	ni, ok := cache.nodes[name]
 	if !ok {
-		klog.ErrorS(nil, "No node info with given name found in the cache", "node", klog.KRef("", name))
+		logger.Error(nil, "No node info with given name found in the cache", "node", klog.KRef("", name))
 		return
 	}
 
@@ -194,7 +197,7 @@ func (cache *cacheImpl) Dump() *Dump {
 // nodeInfo.Node() is guaranteed to be not nil for all the nodes in the snapshot.
 // This function tracks generation number of NodeInfo and updates only the
 // entries of an existing snapshot that have changed after the snapshot was taken.
-func (cache *cacheImpl) UpdateSnapshot(nodeSnapshot *Snapshot) error {
+func (cache *cacheImpl) UpdateSnapshot(logger klog.Logger, nodeSnapshot *Snapshot) error {
 	cache.mu.Lock()
 	defer cache.mu.Unlock()
 
@@ -271,7 +274,7 @@ func (cache *cacheImpl) UpdateSnapshot(nodeSnapshot *Snapshot) error {
 	}
 
 	if updateAllLists || updateNodesHavePodsWithAffinity || updateNodesHavePodsWithRequiredAntiAffinity || updateUsedPVCSet {
-		cache.updateNodeInfoSnapshotList(nodeSnapshot, updateAllLists)
+		cache.updateNodeInfoSnapshotList(logger, nodeSnapshot, updateAllLists)
 	}
 
 	if len(nodeSnapshot.nodeInfoList) != cache.nodeTree.numNodes {
@@ -280,17 +283,17 @@ func (cache *cacheImpl) UpdateSnapshot(nodeSnapshot *Snapshot) error {
 			", trying to recover",
 			len(nodeSnapshot.nodeInfoList), cache.nodeTree.numNodes,
 			len(nodeSnapshot.nodeInfoMap), len(cache.nodes))
-		klog.ErrorS(nil, errMsg)
+		logger.Error(nil, errMsg)
 		// We will try to recover by re-creating the lists for the next scheduling cycle, but still return an
 		// error to surface the problem, the error will likely cause a failure to the current scheduling cycle.
-		cache.updateNodeInfoSnapshotList(nodeSnapshot, true)
+		cache.updateNodeInfoSnapshotList(logger, nodeSnapshot, true)
 		return fmt.Errorf(errMsg)
 	}
 
 	return nil
 }
 
-func (cache *cacheImpl) updateNodeInfoSnapshotList(snapshot *Snapshot, updateAll bool) {
+func (cache *cacheImpl) updateNodeInfoSnapshotList(logger klog.Logger, snapshot *Snapshot, updateAll bool) {
 	snapshot.havePodsWithAffinityNodeInfoList = make([]*framework.NodeInfo, 0, cache.nodeTree.numNodes)
 	snapshot.havePodsWithRequiredAntiAffinityNodeInfoList = make([]*framework.NodeInfo, 0, cache.nodeTree.numNodes)
 	snapshot.usedPVCSet = sets.New[string]()
@@ -299,7 +302,7 @@ func (cache *cacheImpl) updateNodeInfoSnapshotList(snapshot *Snapshot, updateAll
 		snapshot.nodeInfoList = make([]*framework.NodeInfo, 0, cache.nodeTree.numNodes)
 		nodesList, err := cache.nodeTree.list()
 		if err != nil {
-			klog.ErrorS(err, "Error occurred while retrieving the list of names of the nodes from node tree")
+			logger.Error(err, "Error occurred while retrieving the list of names of the nodes from node tree")
 		}
 		for _, nodeName := range nodesList {
 			if nodeInfo := snapshot.nodeInfoMap[nodeName]; nodeInfo != nil {
@@ -314,7 +317,7 @@ func (cache *cacheImpl) updateNodeInfoSnapshotList(snapshot *Snapshot, updateAll
 					snapshot.usedPVCSet.Insert(key)
 				}
 			} else {
-				klog.ErrorS(nil, "Node exists in nodeTree but not in NodeInfoMap, this should not happen", "node", klog.KRef("", nodeName))
+				logger.Error(nil, "Node exists in nodeTree but not in NodeInfoMap, this should not happen", "node", klog.KRef("", nodeName))
 			}
 		}
 	} else {
@@ -369,7 +372,7 @@ func (cache *cacheImpl) PodCount() (int, error) {
 	return count, nil
 }
 
-func (cache *cacheImpl) AssumePod(pod *v1.Pod) error {
+func (cache *cacheImpl) AssumePod(logger klog.Logger, pod *v1.Pod) error {
 	key, err := framework.GetPodKey(pod)
 	if err != nil {
 		return err
@@ -381,15 +384,15 @@ func (cache *cacheImpl) AssumePod(pod *v1.Pod) error {
 		return fmt.Errorf("pod %v(%v) is in the cache, so can't be assumed", key, klog.KObj(pod))
 	}
 
-	return cache.addPod(pod, true)
+	return cache.addPod(logger, pod, true)
 }
 
-func (cache *cacheImpl) FinishBinding(pod *v1.Pod) error {
+func (cache *cacheImpl) FinishBinding(logger klog.Logger, pod *v1.Pod) error {
-	return cache.finishBinding(pod, time.Now())
+	return cache.finishBinding(logger, pod, time.Now())
 }
 
 // finishBinding exists to make tests deterministic by injecting now as an argument
-func (cache *cacheImpl) finishBinding(pod *v1.Pod, now time.Time) error {
+func (cache *cacheImpl) finishBinding(logger klog.Logger, pod *v1.Pod, now time.Time) error {
 	key, err := framework.GetPodKey(pod)
 	if err != nil {
 		return err
@@ -398,7 +401,7 @@ func (cache *cacheImpl) finishBinding(pod *v1.Pod, now time.Time) error {
 	cache.mu.RLock()
 	defer cache.mu.RUnlock()
 
-	klog.V(5).InfoS("Finished binding for pod, can be expired", "podKey", key, "pod", klog.KObj(pod))
+	logger.V(5).Info("Finished binding for pod, can be expired", "podKey", key, "pod", klog.KObj(pod))
 	currState, ok := cache.podStates[key]
 	if ok && cache.assumedPods.Has(key) {
 		if cache.ttl == time.Duration(0) {
@@ -412,7 +415,7 @@ func (cache *cacheImpl) finishBinding(pod *v1.Pod, now time.Time) error {
 	return nil
 }
 
-func (cache *cacheImpl) ForgetPod(pod *v1.Pod) error {
+func (cache *cacheImpl) ForgetPod(logger klog.Logger, pod *v1.Pod) error {
 	key, err := framework.GetPodKey(pod)
 	if err != nil {
 		return err
@@ -428,13 +431,13 @@ func (cache *cacheImpl) ForgetPod(pod *v1.Pod) error {
 
 	// Only assumed pod can be forgotten.
 	if ok && cache.assumedPods.Has(key) {
-		return cache.removePod(pod)
+		return cache.removePod(logger, pod)
 	}
 	return fmt.Errorf("pod %v(%v) wasn't assumed so cannot be forgotten", key, klog.KObj(pod))
 }
 
 // Assumes that lock is already acquired.
-func (cache *cacheImpl) addPod(pod *v1.Pod, assumePod bool) error {
+func (cache *cacheImpl) addPod(logger klog.Logger, pod *v1.Pod, assumePod bool) error {
 	key, err := framework.GetPodKey(pod)
 	if err != nil {
 		return err
@@ -445,7 +448,7 @@ func (cache *cacheImpl) addPod(pod *v1.Pod, assumePod bool) error {
 		cache.nodes[pod.Spec.NodeName] = n
 	}
 	n.info.AddPod(pod)
-	cache.moveNodeInfoToHead(pod.Spec.NodeName)
+	cache.moveNodeInfoToHead(logger, pod.Spec.NodeName)
 	ps := &podState{
 		pod: pod,
 	}
@@ -457,18 +460,18 @@ func (cache *cacheImpl) addPod(pod *v1.Pod, assumePod bool) error {
 }
 
 // Assumes that lock is already acquired.
-func (cache *cacheImpl) updatePod(oldPod, newPod *v1.Pod) error {
+func (cache *cacheImpl) updatePod(logger klog.Logger, oldPod, newPod *v1.Pod) error {
-	if err := cache.removePod(oldPod); err != nil {
+	if err := cache.removePod(logger, oldPod); err != nil {
 		return err
 	}
-	return cache.addPod(newPod, false)
+	return cache.addPod(logger, newPod, false)
 }
 
 // Assumes that lock is already acquired.
 // Removes a pod from the cached node info. If the node information was already
 // removed and there are no more pods left in the node, cleans up the node from
 // the cache.
-func (cache *cacheImpl) removePod(pod *v1.Pod) error {
+func (cache *cacheImpl) removePod(logger klog.Logger, pod *v1.Pod) error {
 	key, err := framework.GetPodKey(pod)
 	if err != nil {
 		return err
@@ -476,16 +479,15 @@ func (cache *cacheImpl) removePod(pod *v1.Pod) error {
 
 	n, ok := cache.nodes[pod.Spec.NodeName]
 	if !ok {
-		klog.ErrorS(nil, "Node not found when trying to remove pod", "node", klog.KRef("", pod.Spec.NodeName), "podKey", key, "pod", klog.KObj(pod))
+		logger.Error(nil, "Node not found when trying to remove pod", "node", klog.KRef("", pod.Spec.NodeName), "podKey", key, "pod", klog.KObj(pod))
-
 	} else {
 		if err := n.info.RemovePod(pod); err != nil {
 			return err
 		}
 		if len(n.info.Pods) == 0 && n.info.Node() == nil {
-			cache.removeNodeInfoFromList(pod.Spec.NodeName)
+			cache.removeNodeInfoFromList(logger, pod.Spec.NodeName)
 		} else {
-			cache.moveNodeInfoToHead(pod.Spec.NodeName)
+			cache.moveNodeInfoToHead(logger, pod.Spec.NodeName)
 		}
 	}
 
@@ -494,7 +496,7 @@ func (cache *cacheImpl) removePod(pod *v1.Pod) error {
 	return nil
 }
 
-func (cache *cacheImpl) AddPod(pod *v1.Pod) error {
+func (cache *cacheImpl) AddPod(logger klog.Logger, pod *v1.Pod) error {
 	key, err := framework.GetPodKey(pod)
 	if err != nil {
 		return err
@@ -508,18 +510,18 @@ func (cache *cacheImpl) AddPod(pod *v1.Pod) error {
 	case ok && cache.assumedPods.Has(key):
 		// When assuming, we've already added the Pod to cache,
 		// Just update here to make sure the Pod's status is up-to-date.
-		if err = cache.updatePod(currState.pod, pod); err != nil {
+		if err = cache.updatePod(logger, currState.pod, pod); err != nil {
-			klog.ErrorS(err, "Error occurred while updating pod")
+			logger.Error(err, "Error occurred while updating pod")
 		}
 		if currState.pod.Spec.NodeName != pod.Spec.NodeName {
 			// The pod was added to a different node than it was assumed to.
-			klog.InfoS("Pod was added to a different node than it was assumed", "podKey", key, "pod", klog.KObj(pod), "assumedNode", klog.KRef("", pod.Spec.NodeName), "currentNode", klog.KRef("", currState.pod.Spec.NodeName))
+			logger.Info("Pod was added to a different node than it was assumed", "podKey", key, "pod", klog.KObj(pod), "assumedNode", klog.KRef("", pod.Spec.NodeName), "currentNode", klog.KRef("", currState.pod.Spec.NodeName))
 			return nil
 		}
 	case !ok:
 		// Pod was expired. We should add it back.
-		if err = cache.addPod(pod, false); err != nil {
+		if err = cache.addPod(logger, pod, false); err != nil {
-			klog.ErrorS(err, "Error occurred while adding pod")
+			logger.Error(err, "Error occurred while adding pod")
 		}
 	default:
 		return fmt.Errorf("pod %v(%v) was already in added state", key, klog.KObj(pod))
@@ -527,7 +529,7 @@ func (cache *cacheImpl) AddPod(pod *v1.Pod) error {
 	return nil
 }
 
-func (cache *cacheImpl) UpdatePod(oldPod, newPod *v1.Pod) error {
+func (cache *cacheImpl) UpdatePod(logger klog.Logger, oldPod, newPod *v1.Pod) error {
 	key, err := framework.GetPodKey(oldPod)
 	if err != nil {
 		return err
@@ -548,14 +550,14 @@ func (cache *cacheImpl) UpdatePod(oldPod, newPod *v1.Pod) error {
 	}
 
 	if currState.pod.Spec.NodeName != newPod.Spec.NodeName {
-		klog.ErrorS(nil, "Pod updated on a different node than previously added to", "podKey", key, "pod", klog.KObj(oldPod))
+		logger.Error(nil, "Pod updated on a different node than previously added to", "podKey", key, "pod", klog.KObj(oldPod))
-		klog.ErrorS(nil, "scheduler cache is corrupted and can badly affect scheduling decisions")
+		logger.Error(nil, "scheduler cache is corrupted and can badly affect scheduling decisions")
 		klog.FlushAndExit(klog.ExitFlushTimeout, 1)
 	}
-	return cache.updatePod(oldPod, newPod)
+	return cache.updatePod(logger, oldPod, newPod)
 }
 
-func (cache *cacheImpl) RemovePod(pod *v1.Pod) error {
+func (cache *cacheImpl) RemovePod(logger klog.Logger, pod *v1.Pod) error {
 	key, err := framework.GetPodKey(pod)
 	if err != nil {
 		return err
@@ -569,15 +571,15 @@ func (cache *cacheImpl) RemovePod(pod *v1.Pod) error {
 		return fmt.Errorf("pod %v(%v) is not found in scheduler cache, so cannot be removed from it", key, klog.KObj(pod))
 	}
 	if currState.pod.Spec.NodeName != pod.Spec.NodeName {
-		klog.ErrorS(nil, "Pod was added to a different node than it was assumed", "podKey", key, "pod", klog.KObj(pod), "assumedNode", klog.KRef("", pod.Spec.NodeName), "currentNode", klog.KRef("", currState.pod.Spec.NodeName))
+		logger.Error(nil, "Pod was added to a different node than it was assumed", "podKey", key, "pod", klog.KObj(pod), "assumedNode", klog.KRef("", pod.Spec.NodeName), "currentNode", klog.KRef("", currState.pod.Spec.NodeName))
 		if pod.Spec.NodeName != "" {
 			// An empty NodeName is possible when the scheduler misses a Delete
 			// event and it gets the last known state from the informer cache.
-			klog.ErrorS(nil, "scheduler cache is corrupted and can badly affect scheduling decisions")
+			logger.Error(nil, "scheduler cache is corrupted and can badly affect scheduling decisions")
 			klog.FlushAndExit(klog.ExitFlushTimeout, 1)
 		}
 	}
-	return cache.removePod(currState.pod)
+	return cache.removePod(logger, currState.pod)
 }
 
 func (cache *cacheImpl) IsAssumedPod(pod *v1.Pod) (bool, error) {
@@ -611,7 +613,7 @@ func (cache *cacheImpl) GetPod(pod *v1.Pod) (*v1.Pod, error) {
 	return podState.pod, nil
 }
 
-func (cache *cacheImpl) AddNode(node *v1.Node) *framework.NodeInfo {
+func (cache *cacheImpl) AddNode(logger klog.Logger, node *v1.Node) *framework.NodeInfo {
 	cache.mu.Lock()
 	defer cache.mu.Unlock()
 
@@ -622,15 +624,15 @@ func (cache *cacheImpl) AddNode(node *v1.Node) *framework.NodeInfo {
 	} else {
 		cache.removeNodeImageStates(n.info.Node())
 	}
-	cache.moveNodeInfoToHead(node.Name)
+	cache.moveNodeInfoToHead(logger, node.Name)
 
-	cache.nodeTree.addNode(node)
+	cache.nodeTree.addNode(logger, node)
 	cache.addNodeImageStates(node, n.info)
 	n.info.SetNode(node)
 	return n.info.Clone()
 }
 
-func (cache *cacheImpl) UpdateNode(oldNode, newNode *v1.Node) *framework.NodeInfo {
+func (cache *cacheImpl) UpdateNode(logger klog.Logger, oldNode, newNode *v1.Node) *framework.NodeInfo {
 	cache.mu.Lock()
 	defer cache.mu.Unlock()
 
@@ -638,13 +640,13 @@ func (cache *cacheImpl) UpdateNode(oldNode, newNode *v1.Node) *framework.NodeInf
 	if !ok {
 		n = newNodeInfoListItem(framework.NewNodeInfo())
 		cache.nodes[newNode.Name] = n
-		cache.nodeTree.addNode(newNode)
+		cache.nodeTree.addNode(logger, newNode)
 	} else {
 		cache.removeNodeImageStates(n.info.Node())
 	}
-	cache.moveNodeInfoToHead(newNode.Name)
+	cache.moveNodeInfoToHead(logger, newNode.Name)
 
-	cache.nodeTree.updateNode(oldNode, newNode)
+	cache.nodeTree.updateNode(logger, oldNode, newNode)
 	cache.addNodeImageStates(newNode, n.info)
 	n.info.SetNode(newNode)
 	return n.info.Clone()
@@ -656,7 +658,7 @@ func (cache *cacheImpl) UpdateNode(oldNode, newNode *v1.Node) *framework.NodeInf
 // the source of truth.
 // However, we keep a ghost node with the list of pods until all pod deletion
 // events have arrived. A ghost node is skipped from snapshots.
-func (cache *cacheImpl) RemoveNode(node *v1.Node) error {
+func (cache *cacheImpl) RemoveNode(logger klog.Logger, node *v1.Node) error {
 	cache.mu.Lock()
 	defer cache.mu.Unlock()
 
@@ -670,11 +672,11 @@ func (cache *cacheImpl) RemoveNode(node *v1.Node) error {
 	// in a different watch, and thus can potentially be observed later, even though
 	// they happened before node removal.
 	if len(n.info.Pods) == 0 {
-		cache.removeNodeInfoFromList(node.Name)
+		cache.removeNodeInfoFromList(logger, node.Name)
 	} else {
-		cache.moveNodeInfoToHead(node.Name)
+		cache.moveNodeInfoToHead(logger, node.Name)
 	}
-	if err := cache.nodeTree.removeNode(node); err != nil {
+	if err := cache.nodeTree.removeNode(logger, node); err != nil {
 		return err
 	}
 	cache.removeNodeImageStates(node)
@@ -732,17 +734,15 @@ func (cache *cacheImpl) removeNodeImageStates(node *v1.Node) {
 	}
 }
 
-func (cache *cacheImpl) run() {
+func (cache *cacheImpl) run(logger klog.Logger) {
-	go wait.Until(cache.cleanupExpiredAssumedPods, cache.period, cache.stop)
+	go wait.Until(func() {
-}
+		cache.cleanupAssumedPods(logger, time.Now())
-
+	}, cache.period, cache.stop)
-func (cache *cacheImpl) cleanupExpiredAssumedPods() {
-	cache.cleanupAssumedPods(time.Now())
 }
 
 // cleanupAssumedPods exists for making test deterministic by taking time as input argument.
 // It also reports metrics on the cache size for nodes, pods, and assumed pods.
-func (cache *cacheImpl) cleanupAssumedPods(now time.Time) {
+func (cache *cacheImpl) cleanupAssumedPods(logger klog.Logger, now time.Time) {
 	cache.mu.Lock()
 	defer cache.mu.Unlock()
 	defer cache.updateMetrics()
@@ -751,17 +751,17 @@ func (cache *cacheImpl) cleanupAssumedPods(now time.Time) {
 	for key := range cache.assumedPods {
 		ps, ok := cache.podStates[key]
 		if !ok {
-			klog.ErrorS(nil, "Key found in assumed set but not in podStates, potentially a logical error")
+			logger.Error(nil, "Key found in assumed set but not in podStates, potentially a logical error")
 			klog.FlushAndExit(klog.ExitFlushTimeout, 1)
 		}
 		if !ps.bindingFinished {
-			klog.V(5).InfoS("Could not expire cache for pod as binding is still in progress", "podKey", key, "pod", klog.KObj(ps.pod))
+			logger.V(5).Info("Could not expire cache for pod as binding is still in progress", "podKey", key, "pod", klog.KObj(ps.pod))
 			continue
 		}
 		if cache.ttl != 0 && now.After(*ps.deadline) {
-			klog.InfoS("Pod expired", "podKey", key, "pod", klog.KObj(ps.pod))
+			logger.Info("Pod expired", "podKey", key, "pod", klog.KObj(ps.pod))
-			if err := cache.removePod(ps.pod); err != nil {
+			if err := cache.removePod(logger, ps.pod); err != nil {
-				klog.ErrorS(err, "ExpirePod failed", "podKey", key, "pod", klog.KObj(ps.pod))
+				logger.Error(err, "ExpirePod failed", "podKey", key, "pod", klog.KObj(ps.pod))
 			}
 		}
 	}

pkg/scheduler/internal/cache/cache_test.go

@@ -17,6 +17,7 @@ limitations under the License.
 package cache
 
 import (
+	"context"
 	"errors"
 	"fmt"
 	"reflect"
@@ -30,6 +31,8 @@ import (
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/types"
 	"k8s.io/apimachinery/pkg/util/sets"
+	"k8s.io/klog/v2"
+	"k8s.io/klog/v2/ktesting"
 	"k8s.io/kubernetes/pkg/scheduler/framework"
 	st "k8s.io/kubernetes/pkg/scheduler/testing"
 	schedutil "k8s.io/kubernetes/pkg/scheduler/util"
@@ -207,13 +210,16 @@ func TestAssumePodScheduled(t *testing.T) {
 
 	for i, tt := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
-			cache := newCache(time.Second, time.Second, nil)
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
+			cache := newCache(ctx, time.Second, time.Second)
 			for _, pod := range tt.pods {
-				if err := cache.AssumePod(pod); err != nil {
+				if err := cache.AssumePod(logger, pod); err != nil {
 					t.Fatalf("AssumePod failed: %v", err)
 				}
 				// pod already in cache so can't be assumed
-				if err := cache.AssumePod(pod); err == nil {
+				if err := cache.AssumePod(logger, pod); err == nil {
 					t.Error("expected error, no error found")
 				}
 			}
@@ -223,7 +229,7 @@ func TestAssumePodScheduled(t *testing.T) {
 			}
 
 			for _, pod := range tt.pods {
-				if err := cache.ForgetPod(pod); err != nil {
+				if err := cache.ForgetPod(logger, pod); err != nil {
 					t.Fatalf("ForgetPod failed: %v", err)
 				}
 				if err := isForgottenFromCache(pod, cache); err != nil {
@@ -240,11 +246,11 @@ type testExpirePodStruct struct {
 	assumedTime time.Time
 }
 
-func assumeAndFinishBinding(cache *cacheImpl, pod *v1.Pod, assumedTime time.Time) error {
+func assumeAndFinishBinding(logger klog.Logger, cache *cacheImpl, pod *v1.Pod, assumedTime time.Time) error {
-	if err := cache.AssumePod(pod); err != nil {
+	if err := cache.AssumePod(logger, pod); err != nil {
 		return err
 	}
-	return cache.finishBinding(pod, assumedTime)
+	return cache.finishBinding(logger, pod, assumedTime)
 }
 
 // TestExpirePod tests that assumed pods will be removed if expired.
@@ -323,22 +329,25 @@ func TestExpirePod(t *testing.T) {
 
 	for _, tc := range tests {
 		t.Run(tc.name, func(t *testing.T) {
-			cache := newCache(tc.ttl, time.Second, nil)
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
+			cache := newCache(ctx, tc.ttl, time.Second)
 
 			for _, pod := range tc.pods {
-				if err := cache.AssumePod(pod.pod); err != nil {
+				if err := cache.AssumePod(logger, pod.pod); err != nil {
 					t.Fatal(err)
 				}
 				if !pod.finishBind {
 					continue
 				}
-				if err := cache.finishBinding(pod.pod, pod.assumedTime); err != nil {
+				if err := cache.finishBinding(logger, pod.pod, pod.assumedTime); err != nil {
 					t.Fatal(err)
 				}
 			}
 			// pods that got bound and have assumedTime + ttl < cleanupTime will get
 			// expired and removed
-			cache.cleanupAssumedPods(tc.cleanupTime)
+			cache.cleanupAssumedPods(logger, tc.cleanupTime)
 			n := cache.nodes[nodeName]
 			if err := deepEqualWithoutGeneration(n, tc.wNodeInfo); err != nil {
 				t.Error(err)
@@ -383,22 +392,25 @@ func TestAddPodWillConfirm(t *testing.T) {
 
 	for i, tt := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
-			cache := newCache(ttl, time.Second, nil)
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
+			cache := newCache(ctx, ttl, time.Second)
 			for _, podToAssume := range tt.podsToAssume {
-				if err := assumeAndFinishBinding(cache, podToAssume, now); err != nil {
+				if err := assumeAndFinishBinding(logger, cache, podToAssume, now); err != nil {
 					t.Fatalf("assumePod failed: %v", err)
 				}
 			}
 			for _, podToAdd := range tt.podsToAdd {
-				if err := cache.AddPod(podToAdd); err != nil {
+				if err := cache.AddPod(logger, podToAdd); err != nil {
 					t.Fatalf("AddPod failed: %v", err)
 				}
 				// pod already in added state
-				if err := cache.AddPod(podToAdd); err == nil {
+				if err := cache.AddPod(logger, podToAdd); err == nil {
 					t.Error("expected error, no error found")
 				}
 			}
-			cache.cleanupAssumedPods(now.Add(2 * ttl))
+			cache.cleanupAssumedPods(logger, now.Add(2*ttl))
 			// check after expiration. confirmed pods shouldn't be expired.
 			n := cache.nodes[nodeName]
 			if err := deepEqualWithoutGeneration(n, tt.wNodeInfo); err != nil {
@@ -427,14 +439,17 @@ func TestDump(t *testing.T) {
 
 	for i, tt := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
-			cache := newCache(ttl, time.Second, nil)
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
+			cache := newCache(ctx, ttl, time.Second)
 			for _, podToAssume := range tt.podsToAssume {
-				if err := assumeAndFinishBinding(cache, podToAssume, now); err != nil {
+				if err := assumeAndFinishBinding(logger, cache, podToAssume, now); err != nil {
 					t.Errorf("assumePod failed: %v", err)
 				}
 			}
 			for _, podToAdd := range tt.podsToAdd {
-				if err := cache.AddPod(podToAdd); err != nil {
+				if err := cache.AddPod(logger, podToAdd); err != nil {
 					t.Errorf("AddPod failed: %v", err)
 				}
 			}
@@ -460,6 +475,9 @@ func TestDump(t *testing.T) {
 // even when the Pod is assumed one.
 func TestAddPodAlwaysUpdatesPodInfoInNodeInfo(t *testing.T) {
 	ttl := 10 * time.Second
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
+	defer cancel()
 	now := time.Now()
 	p1 := makeBasePod(t, "node1", "test-1", "100m", "500", "", []v1.ContainerPort{{HostPort: 80}})
 
@@ -497,14 +515,14 @@ func TestAddPodAlwaysUpdatesPodInfoInNodeInfo(t *testing.T) {
 
 	for i, tt := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
-			cache := newCache(ttl, time.Second, nil)
+			cache := newCache(ctx, ttl, time.Second)
 			for _, podToAssume := range tt.podsToAssume {
-				if err := assumeAndFinishBinding(cache, podToAssume, now); err != nil {
+				if err := assumeAndFinishBinding(logger, cache, podToAssume, now); err != nil {
 					t.Fatalf("assumePod failed: %v", err)
 				}
 			}
 			for _, podToAdd := range tt.podsToAddAfterAssume {
-				if err := cache.AddPod(podToAdd); err != nil {
+				if err := cache.AddPod(logger, podToAdd); err != nil {
 					t.Fatalf("AddPod failed: %v", err)
 				}
 			}
@@ -557,19 +575,22 @@ func TestAddPodWillReplaceAssumed(t *testing.T) {
 
 	for i, tt := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
-			cache := newCache(ttl, time.Second, nil)
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
+			cache := newCache(ctx, ttl, time.Second)
 			for _, podToAssume := range tt.podsToAssume {
-				if err := assumeAndFinishBinding(cache, podToAssume, now); err != nil {
+				if err := assumeAndFinishBinding(logger, cache, podToAssume, now); err != nil {
 					t.Fatalf("assumePod failed: %v", err)
 				}
 			}
 			for _, podToAdd := range tt.podsToAdd {
-				if err := cache.AddPod(podToAdd); err != nil {
+				if err := cache.AddPod(logger, podToAdd); err != nil {
 					t.Fatalf("AddPod failed: %v", err)
 				}
 			}
 			for _, podToUpdate := range tt.podsToUpdate {
-				if err := cache.UpdatePod(podToUpdate[0], podToUpdate[1]); err != nil {
+				if err := cache.UpdatePod(logger, podToUpdate[0], podToUpdate[1]); err != nil {
 					t.Fatalf("UpdatePod failed: %v", err)
 				}
 			}
@@ -611,17 +632,20 @@ func TestAddPodAfterExpiration(t *testing.T) {
 
 	for i, tt := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
 			now := time.Now()
-			cache := newCache(ttl, time.Second, nil)
+			cache := newCache(ctx, ttl, time.Second)
-			if err := assumeAndFinishBinding(cache, tt.pod, now); err != nil {
+			if err := assumeAndFinishBinding(logger, cache, tt.pod, now); err != nil {
 				t.Fatalf("assumePod failed: %v", err)
 			}
-			cache.cleanupAssumedPods(now.Add(2 * ttl))
+			cache.cleanupAssumedPods(logger, now.Add(2*ttl))
 			// It should be expired and removed.
 			if err := isForgottenFromCache(tt.pod, cache); err != nil {
 				t.Error(err)
 			}
-			if err := cache.AddPod(tt.pod); err != nil {
+			if err := cache.AddPod(logger, tt.pod); err != nil {
 				t.Fatalf("AddPod failed: %v", err)
 			}
 			// check after expiration. confirmed pods shouldn't be expired.
@@ -678,9 +702,12 @@ func TestUpdatePod(t *testing.T) {
 
 	for i, tt := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
-			cache := newCache(ttl, time.Second, nil)
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
+			cache := newCache(ctx, ttl, time.Second)
 			for _, podToAdd := range tt.podsToAdd {
-				if err := cache.AddPod(podToAdd); err != nil {
+				if err := cache.AddPod(logger, podToAdd); err != nil {
 					t.Fatalf("AddPod failed: %v", err)
 				}
 			}
@@ -689,7 +716,7 @@ func TestUpdatePod(t *testing.T) {
 				if j == 0 {
 					continue
 				}
-				if err := cache.UpdatePod(tt.podsToUpdate[j-1], tt.podsToUpdate[j]); err != nil {
+				if err := cache.UpdatePod(logger, tt.podsToUpdate[j-1], tt.podsToUpdate[j]); err != nil {
 					t.Fatalf("UpdatePod failed: %v", err)
 				}
 				// check after expiration. confirmed pods shouldn't be expired.
@@ -714,7 +741,7 @@ func TestUpdatePodAndGet(t *testing.T) {
 		pod *v1.Pod
 
 		podToUpdate *v1.Pod
-		handler     func(cache Cache, pod *v1.Pod) error
+		handler     func(logger klog.Logger, cache Cache, pod *v1.Pod) error
 
 		assumePod bool
 	}{
@@ -722,8 +749,8 @@ func TestUpdatePodAndGet(t *testing.T) {
 			pod: testPods[0],
 
 			podToUpdate: testPods[0],
-			handler: func(cache Cache, pod *v1.Pod) error {
+			handler: func(logger klog.Logger, cache Cache, pod *v1.Pod) error {
-				return cache.AssumePod(pod)
+				return cache.AssumePod(logger, pod)
 			},
 			assumePod: true,
 		},
@@ -731,8 +758,8 @@ func TestUpdatePodAndGet(t *testing.T) {
 			pod: testPods[0],
 
 			podToUpdate: testPods[1],
-			handler: func(cache Cache, pod *v1.Pod) error {
+			handler: func(logger klog.Logger, cache Cache, pod *v1.Pod) error {
-				return cache.AddPod(pod)
+				return cache.AddPod(logger, pod)
 			},
 			assumePod: false,
 		},
@@ -740,7 +767,10 @@ func TestUpdatePodAndGet(t *testing.T) {
 
 	for i, tt := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
-			cache := newCache(ttl, time.Second, nil)
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
+			cache := newCache(ctx, ttl, time.Second)
 			// trying to get an unknown pod should return an error
 			// podToUpdate has not been added yet
 			if _, err := cache.GetPod(tt.podToUpdate); err == nil {
@@ -749,16 +779,16 @@ func TestUpdatePodAndGet(t *testing.T) {
 
 			// trying to update an unknown pod should return an error
 			// pod has not been added yet
-			if err := cache.UpdatePod(tt.pod, tt.podToUpdate); err == nil {
+			if err := cache.UpdatePod(logger, tt.pod, tt.podToUpdate); err == nil {
 				t.Error("expected error, no error found")
 			}
 
-			if err := tt.handler(cache, tt.pod); err != nil {
+			if err := tt.handler(logger, cache, tt.pod); err != nil {
 				t.Fatalf("unexpected err: %v", err)
 			}
 
 			if !tt.assumePod {
-				if err := cache.UpdatePod(tt.pod, tt.podToUpdate); err != nil {
+				if err := cache.UpdatePod(logger, tt.pod, tt.podToUpdate); err != nil {
 					t.Fatalf("UpdatePod failed: %v", err)
 				}
 			}
@@ -821,17 +851,20 @@ func TestExpireAddUpdatePod(t *testing.T) {
 
 	for i, tt := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
 			now := time.Now()
-			cache := newCache(ttl, time.Second, nil)
+			cache := newCache(ctx, ttl, time.Second)
 			for _, podToAssume := range tt.podsToAssume {
-				if err := assumeAndFinishBinding(cache, podToAssume, now); err != nil {
+				if err := assumeAndFinishBinding(logger, cache, podToAssume, now); err != nil {
 					t.Fatalf("assumePod failed: %v", err)
 				}
 			}
-			cache.cleanupAssumedPods(now.Add(2 * ttl))
+			cache.cleanupAssumedPods(logger, now.Add(2*ttl))
 
 			for _, podToAdd := range tt.podsToAdd {
-				if err := cache.AddPod(podToAdd); err != nil {
+				if err := cache.AddPod(logger, podToAdd); err != nil {
 					t.Fatalf("AddPod failed: %v", err)
 				}
 			}
@@ -840,7 +873,7 @@ func TestExpireAddUpdatePod(t *testing.T) {
 				if j == 0 {
 					continue
 				}
-				if err := cache.UpdatePod(tt.podsToUpdate[j-1], tt.podsToUpdate[j]); err != nil {
+				if err := cache.UpdatePod(logger, tt.podsToUpdate[j-1], tt.podsToUpdate[j]); err != nil {
 					t.Fatalf("UpdatePod failed: %v", err)
 				}
 				// check after expiration. confirmed pods shouldn't be expired.
@@ -886,8 +919,11 @@ func TestEphemeralStorageResource(t *testing.T) {
 	}
 	for i, tt := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
-			cache := newCache(time.Second, time.Second, nil)
+			logger, ctx := ktesting.NewTestContext(t)
-			if err := cache.AddPod(tt.pod); err != nil {
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
+			cache := newCache(ctx, time.Second, time.Second)
+			if err := cache.AddPod(logger, tt.pod); err != nil {
 				t.Fatalf("AddPod failed: %v", err)
 			}
 			n := cache.nodes[nodeName]
@@ -895,7 +931,7 @@ func TestEphemeralStorageResource(t *testing.T) {
 				t.Error(err)
 			}
 
-			if err := cache.RemovePod(tt.pod); err != nil {
+			if err := cache.RemovePod(logger, tt.pod); err != nil {
 				t.Fatalf("RemovePod failed: %v", err)
 			}
 			if _, err := cache.GetPod(tt.pod); err == nil {
@@ -938,15 +974,18 @@ func TestRemovePod(t *testing.T) {
 
 	for name, tt := range tests {
 		t.Run(name, func(t *testing.T) {
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
 			nodeName := pod.Spec.NodeName
-			cache := newCache(time.Second, time.Second, nil)
+			cache := newCache(ctx, time.Second, time.Second)
 			// Add/Assume pod succeeds even before adding the nodes.
 			if tt.assume {
-				if err := cache.AddPod(pod); err != nil {
+				if err := cache.AddPod(logger, pod); err != nil {
 					t.Fatalf("AddPod failed: %v", err)
 				}
 			} else {
-				if err := cache.AssumePod(pod); err != nil {
+				if err := cache.AssumePod(logger, pod); err != nil {
 					t.Fatalf("AssumePod failed: %v", err)
 				}
 			}
@@ -955,10 +994,10 @@ func TestRemovePod(t *testing.T) {
 				t.Error(err)
 			}
 			for _, n := range nodes {
-				cache.AddNode(n)
+				cache.AddNode(logger, n)
 			}
 
-			if err := cache.RemovePod(pod); err != nil {
+			if err := cache.RemovePod(logger, pod); err != nil {
 				t.Fatalf("RemovePod failed: %v", err)
 			}
 
@@ -967,7 +1006,7 @@ func TestRemovePod(t *testing.T) {
 			}
 
 			// trying to remove a pod already removed should return an error
-			if err := cache.RemovePod(pod); err == nil {
+			if err := cache.RemovePod(logger, pod); err == nil {
 				t.Error("expected error, no error found")
 			}
 
@@ -985,10 +1024,13 @@ func TestForgetPod(t *testing.T) {
 	pods := []*v1.Pod{basePod}
 	now := time.Now()
 	ttl := 10 * time.Second
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
+	defer cancel()
 
-	cache := newCache(ttl, time.Second, nil)
+	cache := newCache(ctx, ttl, time.Second)
 	for _, pod := range pods {
-		if err := assumeAndFinishBinding(cache, pod, now); err != nil {
+		if err := assumeAndFinishBinding(logger, cache, pod, now); err != nil {
 			t.Fatalf("assumePod failed: %v", err)
 		}
 		isAssumed, err := cache.IsAssumedPod(pod)
@@ -1010,14 +1052,14 @@ func TestForgetPod(t *testing.T) {
 		}
 	}
 	for _, pod := range pods {
-		if err := cache.ForgetPod(pod); err != nil {
+		if err := cache.ForgetPod(logger, pod); err != nil {
 			t.Fatalf("ForgetPod failed: %v", err)
 		}
 		if err := isForgottenFromCache(pod, cache); err != nil {
 			t.Errorf("pod %q: %v", pod.Name, err)
 		}
 		// trying to forget a pod already forgotten should return an error
-		if err := cache.ForgetPod(pod); err == nil {
+		if err := cache.ForgetPod(logger, pod); err == nil {
 			t.Error("expected error, no error found")
 		}
 	}
@@ -1169,13 +1211,16 @@ func TestNodeOperators(t *testing.T) {
 
 	for i, test := range tests {
 		t.Run(fmt.Sprintf("case_%d", i), func(t *testing.T) {
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
 			expected := buildNodeInfo(test.node, test.pods)
 			node := test.node
 
-			cache := newCache(time.Second, time.Second, nil)
+			cache := newCache(ctx, time.Second, time.Second)
-			cache.AddNode(node)
+			cache.AddNode(logger, node)
 			for _, pod := range test.pods {
-				if err := cache.AddPod(pod); err != nil {
+				if err := cache.AddPod(logger, pod); err != nil {
 					t.Fatal(err)
 				}
 			}
@@ -1201,7 +1246,7 @@ func TestNodeOperators(t *testing.T) {
 
 			// Step 2: dump cached nodes successfully.
 			cachedNodes := NewEmptySnapshot()
-			if err := cache.UpdateSnapshot(cachedNodes); err != nil {
+			if err := cache.UpdateSnapshot(logger, cachedNodes); err != nil {
 				t.Error(err)
 			}
 			newNode, found := cachedNodes.nodeInfoMap[node.Name]
@@ -1217,7 +1262,7 @@ func TestNodeOperators(t *testing.T) {
 			node.Status.Allocatable[v1.ResourceMemory] = mem50m
 			expected.Allocatable.Memory = mem50m.Value()
 
-			cache.UpdateNode(nil, node)
+			cache.UpdateNode(logger, nil, node)
 			got, found = cache.nodes[node.Name]
 			if !found {
 				t.Errorf("Failed to find node %v in schedulertypes after UpdateNode.", node.Name)
@@ -1240,7 +1285,7 @@ func TestNodeOperators(t *testing.T) {
 			}
 
 			// Step 4: the node can be removed even if it still has pods.
-			if err := cache.RemoveNode(node); err != nil {
+			if err := cache.RemoveNode(logger, node); err != nil {
 				t.Error(err)
 			}
 			if n, err := cache.getNodeInfo(node.Name); err != nil {
@@ -1250,7 +1295,7 @@ func TestNodeOperators(t *testing.T) {
 			}
 
 			// trying to remove a node already removed should return an error
-			if err := cache.RemoveNode(node); err == nil {
+			if err := cache.RemoveNode(logger, node); err == nil {
 				t.Error("expected error, no error found")
 			}
 
@@ -1271,7 +1316,7 @@ func TestNodeOperators(t *testing.T) {
 
 			// Step 5: removing pods for the removed node still succeeds.
 			for _, p := range test.pods {
-				if err := cache.RemovePod(p); err != nil {
+				if err := cache.RemovePod(logger, p); err != nil {
 					t.Error(err)
 				}
 				if _, err := cache.GetPod(p); err == nil {
@@ -1283,6 +1328,8 @@ func TestNodeOperators(t *testing.T) {
 }
 
 func TestSchedulerCache_UpdateSnapshot(t *testing.T) {
+	logger, _ := ktesting.NewTestContext(t)
+
 	// Create a few nodes to be used in tests.
 	var nodes []*v1.Node
 	for i := 0; i < 10; i++ {
@@ -1349,73 +1396,73 @@ func TestSchedulerCache_UpdateSnapshot(t *testing.T) {
 
 	addNode := func(i int) operation {
 		return func(t *testing.T) {
-			cache.AddNode(nodes[i])
+			cache.AddNode(logger, nodes[i])
 		}
 	}
 	removeNode := func(i int) operation {
 		return func(t *testing.T) {
-			if err := cache.RemoveNode(nodes[i]); err != nil {
+			if err := cache.RemoveNode(logger, nodes[i]); err != nil {
 				t.Error(err)
 			}
 		}
 	}
 	updateNode := func(i int) operation {
 		return func(t *testing.T) {
-			cache.UpdateNode(nodes[i], updatedNodes[i])
+			cache.UpdateNode(logger, nodes[i], updatedNodes[i])
 		}
 	}
 	addPod := func(i int) operation {
 		return func(t *testing.T) {
-			if err := cache.AddPod(pods[i]); err != nil {
+			if err := cache.AddPod(logger, pods[i]); err != nil {
 				t.Error(err)
 			}
 		}
 	}
 	addPodWithAffinity := func(i int) operation {
 		return func(t *testing.T) {
-			if err := cache.AddPod(podsWithAffinity[i]); err != nil {
+			if err := cache.AddPod(logger, podsWithAffinity[i]); err != nil {
 				t.Error(err)
 			}
 		}
 	}
 	addPodWithPVC := func(i int) operation {
 		return func(t *testing.T) {
-			if err := cache.AddPod(podsWithPVC[i]); err != nil {
+			if err := cache.AddPod(logger, podsWithPVC[i]); err != nil {
 				t.Error(err)
 			}
 		}
 	}
 	removePod := func(i int) operation {
 		return func(t *testing.T) {
-			if err := cache.RemovePod(pods[i]); err != nil {
+			if err := cache.RemovePod(logger, pods[i]); err != nil {
 				t.Error(err)
 			}
 		}
 	}
 	removePodWithAffinity := func(i int) operation {
 		return func(t *testing.T) {
-			if err := cache.RemovePod(podsWithAffinity[i]); err != nil {
+			if err := cache.RemovePod(logger, podsWithAffinity[i]); err != nil {
 				t.Error(err)
 			}
 		}
 	}
 	removePodWithPVC := func(i int) operation {
 		return func(t *testing.T) {
-			if err := cache.RemovePod(podsWithPVC[i]); err != nil {
+			if err := cache.RemovePod(logger, podsWithPVC[i]); err != nil {
 				t.Error(err)
 			}
 		}
 	}
 	updatePod := func(i int) operation {
 		return func(t *testing.T) {
-			if err := cache.UpdatePod(pods[i], updatedPods[i]); err != nil {
+			if err := cache.UpdatePod(logger, pods[i], updatedPods[i]); err != nil {
 				t.Error(err)
 			}
 		}
 	}
 	updateSnapshot := func() operation {
 		return func(t *testing.T) {
-			cache.UpdateSnapshot(snapshot)
+			cache.UpdateSnapshot(logger, snapshot)
 			if err := compareCacheWithNodeInfoSnapshot(t, cache, snapshot); err != nil {
 				t.Error(err)
 			}
@@ -1637,7 +1684,10 @@ func TestSchedulerCache_UpdateSnapshot(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			cache = newCache(time.Second, time.Second, nil)
+			_, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
+			cache = newCache(ctx, time.Second, time.Second)
 			snapshot = NewEmptySnapshot()
 
 			for _, op := range test.operations {
@@ -1671,7 +1721,7 @@ func TestSchedulerCache_UpdateSnapshot(t *testing.T) {
 			}
 
 			// Always update the snapshot at the end of operations and compare it.
-			if err := cache.UpdateSnapshot(snapshot); err != nil {
+			if err := cache.UpdateSnapshot(logger, snapshot); err != nil {
 				t.Error(err)
 			}
 			if err := compareCacheWithNodeInfoSnapshot(t, cache, snapshot); err != nil {
@@ -1746,6 +1796,8 @@ func compareCacheWithNodeInfoSnapshot(t *testing.T, cache *cacheImpl, snapshot *
 }
 
 func TestSchedulerCache_updateNodeInfoSnapshotList(t *testing.T) {
+	logger, _ := ktesting.NewTestContext(t)
+
 	// Create a few nodes to be used in tests.
 	var nodes []*v1.Node
 	i := 0
@@ -1769,7 +1821,7 @@ func TestSchedulerCache_updateNodeInfoSnapshotList(t *testing.T) {
 	var snapshot *Snapshot
 
 	addNode := func(t *testing.T, i int) {
-		cache.AddNode(nodes[i])
+		cache.AddNode(logger, nodes[i])
 		_, ok := snapshot.nodeInfoMap[nodes[i].Name]
 		if !ok {
 			snapshot.nodeInfoMap[nodes[i].Name] = cache.nodes[nodes[i].Name].info
@@ -1777,7 +1829,7 @@ func TestSchedulerCache_updateNodeInfoSnapshotList(t *testing.T) {
 	}
 
 	updateSnapshot := func(t *testing.T) {
-		cache.updateNodeInfoSnapshotList(snapshot, true)
+		cache.updateNodeInfoSnapshotList(logger, snapshot, true)
 		if err := compareCacheWithNodeInfoSnapshot(t, cache, snapshot); err != nil {
 			t.Error(err)
 		}
@@ -1867,13 +1919,16 @@ func TestSchedulerCache_updateNodeInfoSnapshotList(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			cache = newCache(time.Second, time.Second, nil)
+			_, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
+			defer cancel()
+			cache = newCache(ctx, time.Second, time.Second)
 			snapshot = NewEmptySnapshot()
 
 			test.operations(t)
 
 			// Always update the snapshot at the end of operations and compare it.
-			cache.updateNodeInfoSnapshotList(snapshot, true)
+			cache.updateNodeInfoSnapshotList(logger, snapshot, true)
 			if err := compareCacheWithNodeInfoSnapshot(t, cache, snapshot); err != nil {
 				t.Error(err)
 			}
@@ -1889,11 +1944,12 @@ func TestSchedulerCache_updateNodeInfoSnapshotList(t *testing.T) {
 }
 
 func BenchmarkUpdate1kNodes30kPods(b *testing.B) {
+	logger, _ := ktesting.NewTestContext(b)
 	cache := setupCacheOf1kNodes30kPods(b)
 	b.ResetTimer()
 	for n := 0; n < b.N; n++ {
 		cachedNodes := NewEmptySnapshot()
-		cache.UpdateSnapshot(cachedNodes)
+		cache.UpdateSnapshot(logger, cachedNodes)
 	}
 }
 
@@ -1912,12 +1968,13 @@ func BenchmarkExpirePods(b *testing.B) {
 }
 
 func benchmarkExpire(b *testing.B, podNum int) {
+	logger, _ := ktesting.NewTestContext(b)
 	now := time.Now()
 	for n := 0; n < b.N; n++ {
 		b.StopTimer()
 		cache := setupCacheWithAssumedPods(b, podNum, now)
 		b.StartTimer()
-		cache.cleanupAssumedPods(now.Add(2 * time.Second))
+		cache.cleanupAssumedPods(logger, now.Add(2*time.Second))
 	}
 }
 
@@ -1946,14 +2003,17 @@ func makeBasePod(t testingMode, nodeName, objName, cpu, mem, extended string, po
 }
 
 func setupCacheOf1kNodes30kPods(b *testing.B) Cache {
-	cache := newCache(time.Second, time.Second, nil)
+	logger, ctx := ktesting.NewTestContext(b)
+	ctx, cancel := context.WithCancel(ctx)
+	defer cancel()
+	cache := newCache(ctx, time.Second, time.Second)
 	for i := 0; i < 1000; i++ {
 		nodeName := fmt.Sprintf("node-%d", i)
 		for j := 0; j < 30; j++ {
 			objName := fmt.Sprintf("%s-pod-%d", nodeName, j)
 			pod := makeBasePod(b, nodeName, objName, "0", "0", "", nil)
 
-			if err := cache.AddPod(pod); err != nil {
+			if err := cache.AddPod(logger, pod); err != nil {
 				b.Fatalf("AddPod failed: %v", err)
 			}
 		}
@@ -1962,13 +2022,16 @@ func setupCacheOf1kNodes30kPods(b *testing.B) Cache {
 }
 
 func setupCacheWithAssumedPods(b *testing.B, podNum int, assumedTime time.Time) *cacheImpl {
-	cache := newCache(time.Second, time.Second, nil)
+	logger, ctx := ktesting.NewTestContext(b)
+	ctx, cancel := context.WithCancel(ctx)
+	defer cancel()
+	cache := newCache(ctx, time.Second, time.Second)
 	for i := 0; i < podNum; i++ {
 		nodeName := fmt.Sprintf("node-%d", i/10)
 		objName := fmt.Sprintf("%s-pod-%d", nodeName, i%10)
 		pod := makeBasePod(b, nodeName, objName, "0", "0", "", nil)
 
-		err := assumeAndFinishBinding(cache, pod, assumedTime)
+		err := assumeAndFinishBinding(logger, cache, pod, assumedTime)
 		if err != nil {
 			b.Fatalf("assumePod failed: %v", err)
 		}

pkg/scheduler/internal/cache/debugger/comparer.go

@@ -38,9 +38,9 @@ type CacheComparer struct {
 }
 
 // Compare compares the nodes and pods of NodeLister with Cache.Snapshot.
-func (c *CacheComparer) Compare() error {
+func (c *CacheComparer) Compare(logger klog.Logger) error {
-	klog.V(3).InfoS("Cache comparer started")
+	logger.V(3).Info("Cache comparer started")
-	defer klog.V(3).InfoS("Cache comparer finished")
+	defer logger.V(3).Info("Cache comparer finished")
 
 	nodes, err := c.NodeLister.List(labels.Everything())
 	if err != nil {
@@ -57,11 +57,11 @@ func (c *CacheComparer) Compare() error {
 	pendingPods, _ := c.PodQueue.PendingPods()
 
 	if missed, redundant := c.CompareNodes(nodes, dump.Nodes); len(missed)+len(redundant) != 0 {
-		klog.InfoS("Cache mismatch", "missedNodes", missed, "redundantNodes", redundant)
+		logger.Info("Cache mismatch", "missedNodes", missed, "redundantNodes", redundant)
 	}
 
 	if missed, redundant := c.ComparePods(pods, pendingPods, dump.Nodes); len(missed)+len(redundant) != 0 {
-		klog.InfoS("Cache mismatch", "missedPods", missed, "redundantPods", redundant)
+		logger.Info("Cache mismatch", "missedPods", missed, "redundantPods", redundant)
 	}
 
 	return nil

pkg/scheduler/internal/cache/debugger/debugger.go

@@ -17,10 +17,12 @@ limitations under the License.
 package debugger
 
 import (
+	"context"
 	"os"
 	"os/signal"
 
 	corelisters "k8s.io/client-go/listers/core/v1"
+	"k8s.io/klog/v2"
 	internalcache "k8s.io/kubernetes/pkg/scheduler/internal/cache"
 	internalqueue "k8s.io/kubernetes/pkg/scheduler/internal/queue"
 )
@@ -54,7 +56,9 @@ func New(
 
 // ListenForSignal starts a goroutine that will trigger the CacheDebugger's
 // behavior when the process receives SIGINT (Windows) or SIGUSER2 (non-Windows).
-func (d *CacheDebugger) ListenForSignal(stopCh <-chan struct{}) {
+func (d *CacheDebugger) ListenForSignal(ctx context.Context) {
+	logger := klog.FromContext(ctx)
+	stopCh := ctx.Done()
 	ch := make(chan os.Signal, 1)
 	signal.Notify(ch, compareSignal)
 
@@ -64,8 +68,8 @@ func (d *CacheDebugger) ListenForSignal(stopCh <-chan struct{}) {
 			case <-stopCh:
 				return
 			case <-ch:
-				d.Comparer.Compare()
+				d.Comparer.Compare(logger)
-				d.Dumper.DumpAll()
+				d.Dumper.DumpAll(logger)
 			}
 		}
 	}()

pkg/scheduler/internal/cache/debugger/dumper.go

@@ -36,30 +36,30 @@ type CacheDumper struct {
 }
 
 // DumpAll writes cached nodes and scheduling queue information to the scheduler logs.
-func (d *CacheDumper) DumpAll() {
+func (d *CacheDumper) DumpAll(logger klog.Logger) {
-	d.dumpNodes()
+	d.dumpNodes(logger)
-	d.dumpSchedulingQueue()
+	d.dumpSchedulingQueue(logger)
 }
 
 // dumpNodes writes NodeInfo to the scheduler logs.
-func (d *CacheDumper) dumpNodes() {
+func (d *CacheDumper) dumpNodes(logger klog.Logger) {
 	dump := d.cache.Dump()
 	nodeInfos := make([]string, 0, len(dump.Nodes))
 	for name, nodeInfo := range dump.Nodes {
 		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"))
+	logger.Info("Dump of cached NodeInfo", "nodes", strings.Join(nodeInfos, "\n\n"))
 }
 
 // dumpSchedulingQueue writes pods in the scheduling queue to the scheduler logs.
-func (d *CacheDumper) dumpSchedulingQueue() {
+func (d *CacheDumper) dumpSchedulingQueue(logger klog.Logger) {
 	pendingPods, s := d.podQueue.PendingPods()
 	var podData strings.Builder
 	for _, p := range pendingPods {
 		podData.WriteString(printPod(p))
 	}
-	klog.InfoS("Dump of scheduling queue", "summary", s, "pods", podData.String())
+	logger.Info("Dump of scheduling queue", "summary", s, "pods", podData.String())
 }
 
 // printNodeInfo writes parts of NodeInfo to a string.

pkg/scheduler/internal/cache/fake/fake_cache.go

@@ -18,6 +18,7 @@ package fake
 
 import (
 	v1 "k8s.io/api/core/v1"
+	"k8s.io/klog/v2"
 	"k8s.io/kubernetes/pkg/scheduler/framework"
 	internalcache "k8s.io/kubernetes/pkg/scheduler/internal/cache"
 )
@@ -31,28 +32,28 @@ type Cache struct {
 }
 
 // AssumePod is a fake method for testing.
-func (c *Cache) AssumePod(pod *v1.Pod) error {
+func (c *Cache) AssumePod(logger klog.Logger, pod *v1.Pod) error {
 	c.AssumeFunc(pod)
 	return nil
 }
 
 // FinishBinding is a fake method for testing.
-func (c *Cache) FinishBinding(pod *v1.Pod) error { return nil }
+func (c *Cache) FinishBinding(logger klog.Logger, pod *v1.Pod) error { return nil }
 
 // ForgetPod is a fake method for testing.
-func (c *Cache) ForgetPod(pod *v1.Pod) error {
+func (c *Cache) ForgetPod(logger klog.Logger, pod *v1.Pod) error {
 	c.ForgetFunc(pod)
 	return nil
 }
 
 // AddPod is a fake method for testing.
-func (c *Cache) AddPod(pod *v1.Pod) error { return nil }
+func (c *Cache) AddPod(logger klog.Logger, pod *v1.Pod) error { return nil }
 
 // UpdatePod is a fake method for testing.
-func (c *Cache) UpdatePod(oldPod, newPod *v1.Pod) error { return nil }
+func (c *Cache) UpdatePod(logger klog.Logger, oldPod, newPod *v1.Pod) error { return nil }
 
 // RemovePod is a fake method for testing.
-func (c *Cache) RemovePod(pod *v1.Pod) error { return nil }
+func (c *Cache) RemovePod(logger klog.Logger, pod *v1.Pod) error { return nil }
 
 // IsAssumedPod is a fake method for testing.
 func (c *Cache) IsAssumedPod(pod *v1.Pod) (bool, error) {
@@ -65,16 +66,18 @@ func (c *Cache) GetPod(pod *v1.Pod) (*v1.Pod, error) {
 }
 
 // AddNode is a fake method for testing.
-func (c *Cache) AddNode(node *v1.Node) *framework.NodeInfo { return nil }
+func (c *Cache) AddNode(logger klog.Logger, node *v1.Node) *framework.NodeInfo { return nil }
 
 // UpdateNode is a fake method for testing.
-func (c *Cache) UpdateNode(oldNode, newNode *v1.Node) *framework.NodeInfo { return nil }
+func (c *Cache) UpdateNode(logger klog.Logger, oldNode, newNode *v1.Node) *framework.NodeInfo {
+	return nil
+}
 
 // RemoveNode is a fake method for testing.
-func (c *Cache) RemoveNode(node *v1.Node) error { return nil }
+func (c *Cache) RemoveNode(logger klog.Logger, node *v1.Node) error { return nil }
 
 // UpdateSnapshot is a fake method for testing.
-func (c *Cache) UpdateSnapshot(snapshot *internalcache.Snapshot) error {
+func (c *Cache) UpdateSnapshot(logger klog.Logger, snapshot *internalcache.Snapshot) error {
 	return nil
 }
 

pkg/scheduler/internal/cache/interface.go

@@ -19,6 +19,7 @@ package cache
 import (
 	v1 "k8s.io/api/core/v1"
 	"k8s.io/apimachinery/pkg/util/sets"
+	"k8s.io/klog/v2"
 	"k8s.io/kubernetes/pkg/scheduler/framework"
 )
 
@@ -68,23 +69,23 @@ type Cache interface {
 	// AssumePod assumes a pod scheduled and aggregates the pod's information into its node.
 	// The implementation also decides the policy to expire pod before being confirmed (receiving Add event).
 	// After expiration, its information would be subtracted.
-	AssumePod(pod *v1.Pod) error
+	AssumePod(logger klog.Logger, pod *v1.Pod) error
 
 	// FinishBinding signals that cache for assumed pod can be expired
-	FinishBinding(pod *v1.Pod) error
+	FinishBinding(logger klog.Logger, pod *v1.Pod) error
 
 	// ForgetPod removes an assumed pod from cache.
-	ForgetPod(pod *v1.Pod) error
+	ForgetPod(logger klog.Logger, pod *v1.Pod) error
 
 	// AddPod either confirms a pod if it's assumed, or adds it back if it's expired.
 	// If added back, the pod's information would be added again.
-	AddPod(pod *v1.Pod) error
+	AddPod(logger klog.Logger, pod *v1.Pod) error
 
 	// UpdatePod removes oldPod's information and adds newPod's information.
-	UpdatePod(oldPod, newPod *v1.Pod) error
+	UpdatePod(logger klog.Logger, oldPod, newPod *v1.Pod) error
 
 	// RemovePod removes a pod. The pod's information would be subtracted from assigned node.
-	RemovePod(pod *v1.Pod) error
+	RemovePod(logger klog.Logger, pod *v1.Pod) error
 
 	// GetPod returns the pod from the cache with the same namespace and the
 	// same name of the specified pod.
@@ -95,21 +96,21 @@ type Cache interface {
 
 	// AddNode adds overall information about node.
 	// It returns a clone of added NodeInfo object.
-	AddNode(node *v1.Node) *framework.NodeInfo
+	AddNode(logger klog.Logger, node *v1.Node) *framework.NodeInfo
 
 	// UpdateNode updates overall information about node.
 	// It returns a clone of updated NodeInfo object.
-	UpdateNode(oldNode, newNode *v1.Node) *framework.NodeInfo
+	UpdateNode(logger klog.Logger, oldNode, newNode *v1.Node) *framework.NodeInfo
 
 	// RemoveNode removes overall information about node.
-	RemoveNode(node *v1.Node) error
+	RemoveNode(logger klog.Logger, node *v1.Node) error
 
 	// UpdateSnapshot updates the passed infoSnapshot to the current contents of Cache.
 	// The node info contains aggregated information of pods scheduled (including assumed to be)
 	// on this node.
 	// The snapshot only includes Nodes that are not deleted at the time this function is called.
 	// nodeinfo.Node() is guaranteed to be not nil for all the nodes in the snapshot.
-	UpdateSnapshot(nodeSnapshot *Snapshot) error
+	UpdateSnapshot(logger klog.Logger, nodeSnapshot *Snapshot) error
 
 	// Dump produces a dump of the current cache.
 	Dump() *Dump

pkg/scheduler/internal/cache/node_tree.go

@@ -36,24 +36,24 @@ type nodeTree struct {
 }
 
 // newNodeTree creates a NodeTree from nodes.
-func newNodeTree(nodes []*v1.Node) *nodeTree {
+func newNodeTree(logger klog.Logger, nodes []*v1.Node) *nodeTree {
 	nt := &nodeTree{
 		tree: make(map[string][]string, len(nodes)),
 	}
 	for _, n := range nodes {
-		nt.addNode(n)
+		nt.addNode(logger, n)
 	}
 	return nt
 }
 
 // addNode adds a node and its corresponding zone to the tree. If the zone already exists, the node
 // is added to the array of nodes in that zone.
-func (nt *nodeTree) addNode(n *v1.Node) {
+func (nt *nodeTree) addNode(logger klog.Logger, n *v1.Node) {
 	zone := utilnode.GetZoneKey(n)
 	if na, ok := nt.tree[zone]; ok {
 		for _, nodeName := range na {
 			if nodeName == n.Name {
-				klog.InfoS("Node already exists in the NodeTree", "node", klog.KObj(n))
+				logger.Info("Did not add to the NodeTree because it already exists", "node", klog.KObj(n))
 				return
 			}
 		}
@@ -62,12 +62,12 @@ func (nt *nodeTree) addNode(n *v1.Node) {
 		nt.zones = append(nt.zones, zone)
 		nt.tree[zone] = []string{n.Name}
 	}
-	klog.V(2).InfoS("Added node in listed group to NodeTree", "node", klog.KObj(n), "zone", zone)
+	logger.V(2).Info("Added node in listed group to NodeTree", "node", klog.KObj(n), "zone", zone)
 	nt.numNodes++
 }
 
 // removeNode removes a node from the NodeTree.
-func (nt *nodeTree) removeNode(n *v1.Node) error {
+func (nt *nodeTree) removeNode(logger klog.Logger, n *v1.Node) error {
 	zone := utilnode.GetZoneKey(n)
 	if na, ok := nt.tree[zone]; ok {
 		for i, nodeName := range na {
@@ -76,13 +76,13 @@ func (nt *nodeTree) removeNode(n *v1.Node) error {
 				if len(nt.tree[zone]) == 0 {
 					nt.removeZone(zone)
 				}
-				klog.V(2).InfoS("Removed node in listed group from NodeTree", "node", klog.KObj(n), "zone", zone)
+				logger.V(2).Info("Removed node in listed group from NodeTree", "node", klog.KObj(n), "zone", zone)
 				nt.numNodes--
 				return nil
 			}
 		}
 	}
-	klog.ErrorS(nil, "Node in listed group was not found", "node", klog.KObj(n), "zone", zone)
+	logger.Error(nil, "Did not remove Node in NodeTree because it was not found", "node", klog.KObj(n), "zone", zone)
 	return fmt.Errorf("node %q in group %q was not found", n.Name, zone)
 }
 
@@ -99,7 +99,7 @@ func (nt *nodeTree) removeZone(zone string) {
 }
 
 // updateNode updates a node in the NodeTree.
-func (nt *nodeTree) updateNode(old, new *v1.Node) {
+func (nt *nodeTree) updateNode(logger klog.Logger, old, new *v1.Node) {
 	var oldZone string
 	if old != nil {
 		oldZone = utilnode.GetZoneKey(old)
@@ -110,8 +110,8 @@ func (nt *nodeTree) updateNode(old, new *v1.Node) {
 	if oldZone == newZone {
 		return
 	}
-	nt.removeNode(old) // No error checking. We ignore whether the old node exists or not.
+	nt.removeNode(logger, old) // No error checking. We ignore whether the old node exists or not.
-	nt.addNode(new)
+	nt.addNode(logger, new)
 }
 
 // list returns the list of names of the node. NodeTree iterates over zones and in each zone iterates

pkg/scheduler/internal/cache/node_tree_test.go

@@ -22,6 +22,7 @@ import (
 
 	v1 "k8s.io/api/core/v1"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
+	"k8s.io/klog/v2/ktesting"
 )
 
 var allNodes = []*v1.Node{
@@ -204,9 +205,10 @@ func TestNodeTree_AddNode(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			nt := newNodeTree(nil)
+			logger, _ := ktesting.NewTestContext(t)
+			nt := newNodeTree(logger, nil)
 			for _, n := range test.nodesToAdd {
-				nt.addNode(n)
+				nt.addNode(logger, n)
 			}
 			verifyNodeTree(t, nt, test.expectedTree)
 		})
@@ -261,9 +263,10 @@ func TestNodeTree_RemoveNode(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			nt := newNodeTree(test.existingNodes)
+			logger, _ := ktesting.NewTestContext(t)
+			nt := newNodeTree(logger, test.existingNodes)
 			for _, n := range test.nodesToRemove {
-				err := nt.removeNode(n)
+				err := nt.removeNode(logger, n)
 				if test.expectError == (err == nil) {
 					t.Errorf("unexpected returned error value: %v", err)
 				}
@@ -337,7 +340,8 @@ func TestNodeTree_UpdateNode(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			nt := newNodeTree(test.existingNodes)
+			logger, _ := ktesting.NewTestContext(t)
+			nt := newNodeTree(logger, test.existingNodes)
 			var oldNode *v1.Node
 			for _, n := range allNodes {
 				if n.Name == test.nodeToUpdate.Name {
@@ -348,7 +352,7 @@ func TestNodeTree_UpdateNode(t *testing.T) {
 			if oldNode == nil {
 				oldNode = &v1.Node{ObjectMeta: metav1.ObjectMeta{Name: "nonexisting-node"}}
 			}
-			nt.updateNode(oldNode, test.nodeToUpdate)
+			nt.updateNode(logger, oldNode, test.nodeToUpdate)
 			verifyNodeTree(t, nt, test.expectedTree)
 		})
 	}
@@ -384,7 +388,8 @@ func TestNodeTree_List(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			nt := newNodeTree(test.nodesToAdd)
+			logger, _ := ktesting.NewTestContext(t)
+			nt := newNodeTree(logger, test.nodesToAdd)
 
 			output, err := nt.list()
 			if err != nil {
@@ -398,7 +403,8 @@ func TestNodeTree_List(t *testing.T) {
 }
 
 func TestNodeTree_List_Exhausted(t *testing.T) {
-	nt := newNodeTree(allNodes[:9])
+	logger, _ := ktesting.NewTestContext(t)
+	nt := newNodeTree(logger, allNodes[:9])
 	nt.numNodes++
 	_, err := nt.list()
 	if err == nil {
@@ -453,7 +459,8 @@ func TestNodeTreeMultiOperations(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			nt := newNodeTree(nil)
+			logger, _ := ktesting.NewTestContext(t)
+			nt := newNodeTree(logger, nil)
 			addIndex := 0
 			removeIndex := 0
 			for _, op := range test.operations {
@@ -462,14 +469,14 @@ func TestNodeTreeMultiOperations(t *testing.T) {
 					if addIndex >= len(test.nodesToAdd) {
 						t.Error("more add operations than nodesToAdd")
 					} else {
-						nt.addNode(test.nodesToAdd[addIndex])
+						nt.addNode(logger, test.nodesToAdd[addIndex])
 						addIndex++
 					}
 				case "remove":
 					if removeIndex >= len(test.nodesToRemove) {
 						t.Error("more remove operations than nodesToRemove")
 					} else {
-						nt.removeNode(test.nodesToRemove[removeIndex])
+						nt.removeNode(logger, test.nodesToRemove[removeIndex])
 						removeIndex++
 					}
 				default:

pkg/scheduler/internal/queue/scheduling_queue.go

@@ -91,15 +91,15 @@ type PreEnqueueCheck func(pod *v1.Pod) bool
 // makes it easy to use those data structures as a SchedulingQueue.
 type SchedulingQueue interface {
 	framework.PodNominator
-	Add(pod *v1.Pod) error
+	Add(logger klog.Logger, pod *v1.Pod) error
 	// Activate moves the given pods to activeQ iff they're in unschedulablePods or backoffQ.
 	// The passed-in pods are originally compiled from plugins that want to activate Pods,
 	// by injecting the pods through a reserved CycleState struct (PodsToActivate).
-	Activate(pods map[string]*v1.Pod)
+	Activate(logger klog.Logger, pods map[string]*v1.Pod)
 	// AddUnschedulableIfNotPresent adds an unschedulable pod back to scheduling queue.
 	// The podSchedulingCycle represents the current scheduling cycle number which can be
 	// returned by calling SchedulingCycle().
-	AddUnschedulableIfNotPresent(pod *framework.QueuedPodInfo, podSchedulingCycle int64) error
+	AddUnschedulableIfNotPresent(logger klog.Logger, pod *framework.QueuedPodInfo, podSchedulingCycle int64) error
 	// SchedulingCycle returns the current number of scheduling cycle which is
 	// cached by scheduling queue. Normally, incrementing this number whenever
 	// a pod is popped (e.g. called Pop()) is enough.
@@ -107,17 +107,17 @@ type SchedulingQueue interface {
 	// Pop removes the head of the queue and returns it. It blocks if the
 	// queue is empty and waits until a new item is added to the queue.
 	Pop() (*framework.QueuedPodInfo, error)
-	Update(oldPod, newPod *v1.Pod) error
+	Update(logger klog.Logger, oldPod, newPod *v1.Pod) error
 	Delete(pod *v1.Pod) error
-	MoveAllToActiveOrBackoffQueue(event framework.ClusterEvent, preCheck PreEnqueueCheck)
+	MoveAllToActiveOrBackoffQueue(logger klog.Logger, event framework.ClusterEvent, preCheck PreEnqueueCheck)
-	AssignedPodAdded(pod *v1.Pod)
+	AssignedPodAdded(logger klog.Logger, pod *v1.Pod)
-	AssignedPodUpdated(pod *v1.Pod)
+	AssignedPodUpdated(logger klog.Logger, pod *v1.Pod)
 	PendingPods() ([]*v1.Pod, string)
 	// Close closes the SchedulingQueue so that the goroutine which is
 	// waiting to pop items can exit gracefully.
 	Close()
 	// Run starts the goroutines managing the queue.
-	Run()
+	Run(logger klog.Logger)
 }
 
 // NewSchedulingQueue initializes a priority queue as a new scheduling queue.
@@ -330,9 +330,13 @@ func NewPriorityQueue(
 }
 
 // Run starts the goroutine to pump from podBackoffQ to activeQ
-func (p *PriorityQueue) Run() {
+func (p *PriorityQueue) Run(logger klog.Logger) {
-	go wait.Until(p.flushBackoffQCompleted, 1.0*time.Second, p.stop)
+	go wait.Until(func() {
-	go wait.Until(p.flushUnschedulablePodsLeftover, 30*time.Second, p.stop)
+		p.flushBackoffQCompleted(logger)
+	}, 1.0*time.Second, p.stop)
+	go wait.Until(func() {
+		p.flushUnschedulablePodsLeftover(logger)
+	}, 30*time.Second, p.stop)
 }
 
 // runPreEnqueuePlugins iterates PreEnqueue function in each registered PreEnqueuePlugin.
@@ -341,6 +345,7 @@ func (p *PriorityQueue) Run() {
 // Note: we need to associate the failed plugin to `pInfo`, so that the pod can be moved back
 // to activeQ by related cluster event.
 func (p *PriorityQueue) runPreEnqueuePlugins(ctx context.Context, pInfo *framework.QueuedPodInfo) bool {
+	logger := klog.FromContext(ctx)
 	var s *framework.Status
 	pod := pInfo.Pod
 	startTime := time.Now()
@@ -357,9 +362,9 @@ func (p *PriorityQueue) runPreEnqueuePlugins(ctx context.Context, pInfo *framewo
 		pInfo.UnschedulablePlugins.Insert(pl.Name())
 		metrics.UnschedulableReason(pl.Name(), pod.Spec.SchedulerName).Inc()
 		if s.Code() == framework.Error {
-			klog.ErrorS(s.AsError(), "Unexpected error running PreEnqueue plugin", "pod", klog.KObj(pod), "plugin", pl.Name())
+			logger.Error(s.AsError(), "Unexpected error running PreEnqueue plugin", "pod", klog.KObj(pod), "plugin", pl.Name())
 		} else {
-			klog.V(5).InfoS("Status after running PreEnqueue plugin", "pod", klog.KObj(pod), "plugin", pl.Name(), "status", s)
+			logger.Info("Status after running PreEnqueue plugin", "pod", klog.KObj(pod), "plugin", pl.Name(), "status", s)
 		}
 		return false
 	}
@@ -379,7 +384,7 @@ func (p *PriorityQueue) runPreEnqueuePlugin(ctx context.Context, pl framework.Pr
 // addToActiveQ tries to add pod to active queue. It returns 2 parameters:
 // 1. a boolean flag to indicate whether the pod is added successfully.
 // 2. an error for the caller to act on.
-func (p *PriorityQueue) addToActiveQ(pInfo *framework.QueuedPodInfo) (bool, error) {
+func (p *PriorityQueue) addToActiveQ(logger klog.Logger, pInfo *framework.QueuedPodInfo) (bool, error) {
 	pInfo.Gated = !p.runPreEnqueuePlugins(context.Background(), pInfo)
 	if pInfo.Gated {
 		// Add the Pod to unschedulablePods if it's not passing PreEnqueuePlugins.
@@ -387,7 +392,7 @@ func (p *PriorityQueue) addToActiveQ(pInfo *framework.QueuedPodInfo) (bool, erro
 		return false, nil
 	}
 	if err := p.activeQ.Add(pInfo); err != nil {
-		klog.ErrorS(err, "Error adding pod to the active queue", "pod", klog.KObj(pInfo.Pod))
+		logger.Error(err, "Error adding pod to the active queue", "pod", klog.KObj(pInfo.Pod))
 		return false, err
 	}
 	return true, nil
@@ -395,39 +400,39 @@ func (p *PriorityQueue) addToActiveQ(pInfo *framework.QueuedPodInfo) (bool, erro
 
 // Add adds a pod to the active queue. It should be called only when a new pod
 // is added so there is no chance the pod is already in active/unschedulable/backoff queues
-func (p *PriorityQueue) Add(pod *v1.Pod) error {
+func (p *PriorityQueue) Add(logger klog.Logger, pod *v1.Pod) error {
 	p.lock.Lock()
 	defer p.lock.Unlock()
 
 	pInfo := p.newQueuedPodInfo(pod)
 	gated := pInfo.Gated
-	if added, err := p.addToActiveQ(pInfo); !added {
+	if added, err := p.addToActiveQ(logger, pInfo); !added {
 		return err
 	}
 	if p.unschedulablePods.get(pod) != nil {
-		klog.ErrorS(nil, "Error: pod is already in the unschedulable queue", "pod", klog.KObj(pod))
+		logger.Error(nil, "Error: pod is already in the unschedulable queue", "pod", klog.KObj(pod))
 		p.unschedulablePods.delete(pod, gated)
 	}
 	// Delete pod from backoffQ if it is backing off
 	if err := p.podBackoffQ.Delete(pInfo); err == nil {
-		klog.ErrorS(nil, "Error: pod is already in the podBackoff queue", "pod", klog.KObj(pod))
+		logger.Error(nil, "Error: pod is already in the podBackoff queue", "pod", klog.KObj(pod))
 	}
-	klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pod), "event", PodAdd, "queue", activeQName)
+	logger.V(5).Info("Pod moved to an internal scheduling queue", "pod", klog.KObj(pod), "event", PodAdd, "queue", activeQName)
 	metrics.SchedulerQueueIncomingPods.WithLabelValues("active", PodAdd).Inc()
-	p.addNominatedPodUnlocked(pInfo.PodInfo, nil)
+	p.addNominatedPodUnlocked(logger, pInfo.PodInfo, nil)
 	p.cond.Broadcast()
 
 	return nil
 }
 
 // Activate moves the given pods to activeQ iff they're in unschedulablePods or backoffQ.
-func (p *PriorityQueue) Activate(pods map[string]*v1.Pod) {
+func (p *PriorityQueue) Activate(logger klog.Logger, pods map[string]*v1.Pod) {
 	p.lock.Lock()
 	defer p.lock.Unlock()
 
 	activated := false
 	for _, pod := range pods {
-		if p.activate(pod) {
+		if p.activate(logger, pod) {
 			activated = true
 		}
 	}
@@ -437,7 +442,7 @@ func (p *PriorityQueue) Activate(pods map[string]*v1.Pod) {
 	}
 }
 
-func (p *PriorityQueue) activate(pod *v1.Pod) bool {
+func (p *PriorityQueue) activate(logger klog.Logger, pod *v1.Pod) bool {
 	// Verify if the pod is present in activeQ.
 	if _, exists, _ := p.activeQ.Get(newQueuedPodInfoForLookup(pod)); exists {
 		// No need to activate if it's already present in activeQ.
@@ -448,7 +453,7 @@ func (p *PriorityQueue) activate(pod *v1.Pod) bool {
 	if pInfo = p.unschedulablePods.get(pod); pInfo == nil {
 		// If the pod doesn't belong to unschedulablePods or backoffQ, don't activate it.
 		if obj, exists, _ := p.podBackoffQ.Get(newQueuedPodInfoForLookup(pod)); !exists {
-			klog.ErrorS(nil, "To-activate pod does not exist in unschedulablePods or backoffQ", "pod", klog.KObj(pod))
+			logger.Error(nil, "To-activate pod does not exist in unschedulablePods or backoffQ", "pod", klog.KObj(pod))
 			return false
 		} else {
 			pInfo = obj.(*framework.QueuedPodInfo)
@@ -457,18 +462,18 @@ func (p *PriorityQueue) activate(pod *v1.Pod) bool {
 
 	if pInfo == nil {
 		// Redundant safe check. We shouldn't reach here.
-		klog.ErrorS(nil, "Internal error: cannot obtain pInfo")
+		logger.Error(nil, "Internal error: cannot obtain pInfo")
 		return false
 	}
 
 	gated := pInfo.Gated
-	if added, _ := p.addToActiveQ(pInfo); !added {
+	if added, _ := p.addToActiveQ(logger, pInfo); !added {
 		return false
 	}
 	p.unschedulablePods.delete(pInfo.Pod, gated)
 	p.podBackoffQ.Delete(pInfo)
 	metrics.SchedulerQueueIncomingPods.WithLabelValues("active", ForceActivate).Inc()
-	p.addNominatedPodUnlocked(pInfo.PodInfo, nil)
+	p.addNominatedPodUnlocked(logger, pInfo.PodInfo, nil)
 	return true
 }
 
@@ -493,7 +498,7 @@ func (p *PriorityQueue) SchedulingCycle() int64 {
 // the queue, unless it is already in the queue. Normally, PriorityQueue puts
 // unschedulable pods in `unschedulablePods`. But if there has been a recent move
 // request, then the pod is put in `podBackoffQ`.
-func (p *PriorityQueue) AddUnschedulableIfNotPresent(pInfo *framework.QueuedPodInfo, podSchedulingCycle int64) error {
+func (p *PriorityQueue) AddUnschedulableIfNotPresent(logger klog.Logger, pInfo *framework.QueuedPodInfo, podSchedulingCycle int64) error {
 	p.lock.Lock()
 	defer p.lock.Unlock()
 	pod := pInfo.Pod
@@ -520,21 +525,21 @@ func (p *PriorityQueue) AddUnschedulableIfNotPresent(pInfo *framework.QueuedPodI
 		if err := p.podBackoffQ.Add(pInfo); err != nil {
 			return fmt.Errorf("error adding pod %v to the backoff queue: %v", klog.KObj(pod), err)
 		}
-		klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pod), "event", ScheduleAttemptFailure, "queue", backoffQName)
+		logger.V(5).Info("Pod moved to an internal scheduling queue", "pod", klog.KObj(pod), "event", ScheduleAttemptFailure, "queue", backoffQName)
 		metrics.SchedulerQueueIncomingPods.WithLabelValues("backoff", ScheduleAttemptFailure).Inc()
 	} else {
 		p.unschedulablePods.addOrUpdate(pInfo)
-		klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pod), "event", ScheduleAttemptFailure, "queue", unschedulablePods)
+		logger.V(5).Info("Pod moved to an internal scheduling queue", "pod", klog.KObj(pod), "event", ScheduleAttemptFailure, "queue", unschedulablePods)
 		metrics.SchedulerQueueIncomingPods.WithLabelValues("unschedulable", ScheduleAttemptFailure).Inc()
 
 	}
 
-	p.addNominatedPodUnlocked(pInfo.PodInfo, nil)
+	p.addNominatedPodUnlocked(logger, pInfo.PodInfo, nil)
 	return nil
 }
 
 // flushBackoffQCompleted Moves all pods from backoffQ which have completed backoff in to activeQ
-func (p *PriorityQueue) flushBackoffQCompleted() {
+func (p *PriorityQueue) flushBackoffQCompleted(logger klog.Logger) {
 	p.lock.Lock()
 	defer p.lock.Unlock()
 	activated := false
@@ -550,11 +555,11 @@ func (p *PriorityQueue) flushBackoffQCompleted() {
 		}
 		_, err := p.podBackoffQ.Pop()
 		if err != nil {
-			klog.ErrorS(err, "Unable to pop pod from backoff queue despite backoff completion", "pod", klog.KObj(pod))
+			logger.Error(err, "Unable to pop pod from backoff queue despite backoff completion", "pod", klog.KObj(pod))
 			break
 		}
-		if added, _ := p.addToActiveQ(pInfo); added {
+		if added, _ := p.addToActiveQ(logger, pInfo); added {
-			klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pod), "event", BackoffComplete, "queue", activeQName)
+			logger.V(5).Info("Pod moved to an internal scheduling queue", "pod", klog.KObj(pod), "event", BackoffComplete, "queue", activeQName)
 			metrics.SchedulerQueueIncomingPods.WithLabelValues("active", BackoffComplete).Inc()
 			activated = true
 		}
@@ -567,7 +572,7 @@ func (p *PriorityQueue) flushBackoffQCompleted() {
 
 // flushUnschedulablePodsLeftover moves pods which stay in unschedulablePods
 // longer than podMaxInUnschedulablePodsDuration to backoffQ or activeQ.
-func (p *PriorityQueue) flushUnschedulablePodsLeftover() {
+func (p *PriorityQueue) flushUnschedulablePodsLeftover(logger klog.Logger) {
 	p.lock.Lock()
 	defer p.lock.Unlock()
 
@@ -581,7 +586,7 @@ func (p *PriorityQueue) flushUnschedulablePodsLeftover() {
 	}
 
 	if len(podsToMove) > 0 {
-		p.movePodsToActiveOrBackoffQueue(podsToMove, UnschedulableTimeout)
+		p.movePodsToActiveOrBackoffQueue(logger, podsToMove, UnschedulableTimeout)
 	}
 }
 
@@ -629,7 +634,7 @@ func isPodUpdated(oldPod, newPod *v1.Pod) bool {
 // the item from the unschedulable queue if pod is updated in a way that it may
 // become schedulable and adds the updated one to the active queue.
 // If pod is not present in any of the queues, it is added to the active queue.
-func (p *PriorityQueue) Update(oldPod, newPod *v1.Pod) error {
+func (p *PriorityQueue) Update(logger klog.Logger, oldPod, newPod *v1.Pod) error {
 	p.lock.Lock()
 	defer p.lock.Unlock()
 
@@ -638,14 +643,14 @@ func (p *PriorityQueue) Update(oldPod, newPod *v1.Pod) error {
 		// If the pod is already in the active queue, just update it there.
 		if oldPodInfo, exists, _ := p.activeQ.Get(oldPodInfo); exists {
 			pInfo := updatePod(oldPodInfo, newPod)
-			p.updateNominatedPodUnlocked(oldPod, pInfo.PodInfo)
+			p.updateNominatedPodUnlocked(logger, oldPod, pInfo.PodInfo)
 			return p.activeQ.Update(pInfo)
 		}
 
 		// If the pod is in the backoff queue, update it there.
 		if oldPodInfo, exists, _ := p.podBackoffQ.Get(oldPodInfo); exists {
 			pInfo := updatePod(oldPodInfo, newPod)
-			p.updateNominatedPodUnlocked(oldPod, pInfo.PodInfo)
+			p.updateNominatedPodUnlocked(logger, oldPod, pInfo.PodInfo)
 			return p.podBackoffQ.Update(pInfo)
 		}
 	}
@@ -653,7 +658,7 @@ func (p *PriorityQueue) Update(oldPod, newPod *v1.Pod) error {
 	// If the pod is in the unschedulable queue, updating it may make it schedulable.
 	if usPodInfo := p.unschedulablePods.get(newPod); usPodInfo != nil {
 		pInfo := updatePod(usPodInfo, newPod)
-		p.updateNominatedPodUnlocked(oldPod, pInfo.PodInfo)
+		p.updateNominatedPodUnlocked(logger, oldPod, pInfo.PodInfo)
 		if isPodUpdated(oldPod, newPod) {
 			gated := usPodInfo.Gated
 			if p.isPodBackingoff(usPodInfo) {
@@ -661,13 +666,13 @@ func (p *PriorityQueue) Update(oldPod, newPod *v1.Pod) error {
 					return err
 				}
 				p.unschedulablePods.delete(usPodInfo.Pod, gated)
-				klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", PodUpdate, "queue", backoffQName)
+				logger.V(5).Info("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", PodUpdate, "queue", backoffQName)
 			} else {
-				if added, err := p.addToActiveQ(pInfo); !added {
+				if added, err := p.addToActiveQ(logger, pInfo); !added {
 					return err
 				}
 				p.unschedulablePods.delete(usPodInfo.Pod, gated)
-				klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", BackoffComplete, "queue", activeQName)
+				logger.V(5).Info("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", BackoffComplete, "queue", activeQName)
 				p.cond.Broadcast()
 			}
 		} else {
@@ -679,11 +684,11 @@ func (p *PriorityQueue) Update(oldPod, newPod *v1.Pod) error {
 	}
 	// If pod is not in any of the queues, we put it in the active queue.
 	pInfo := p.newQueuedPodInfo(newPod)
-	if added, err := p.addToActiveQ(pInfo); !added {
+	if added, err := p.addToActiveQ(logger, pInfo); !added {
 		return err
 	}
-	p.addNominatedPodUnlocked(pInfo.PodInfo, nil)
+	p.addNominatedPodUnlocked(logger, pInfo.PodInfo, nil)
-	klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", PodUpdate, "queue", activeQName)
+	logger.V(5).Info("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", PodUpdate, "queue", activeQName)
 	p.cond.Broadcast()
 	return nil
 }
@@ -707,9 +712,9 @@ func (p *PriorityQueue) Delete(pod *v1.Pod) error {
 
 // AssignedPodAdded is called when a bound pod is added. Creation of this pod
 // may make pending pods with matching affinity terms schedulable.
-func (p *PriorityQueue) AssignedPodAdded(pod *v1.Pod) {
+func (p *PriorityQueue) AssignedPodAdded(logger klog.Logger, pod *v1.Pod) {
 	p.lock.Lock()
-	p.movePodsToActiveOrBackoffQueue(p.getUnschedulablePodsWithMatchingAffinityTerm(pod), AssignedPodAdd)
+	p.movePodsToActiveOrBackoffQueue(logger, p.getUnschedulablePodsWithMatchingAffinityTerm(pod), AssignedPodAdd)
 	p.lock.Unlock()
 }
 
@@ -729,12 +734,12 @@ func isPodResourcesResizedDown(pod *v1.Pod) bool {
 
 // AssignedPodUpdated is called when a bound pod is updated. Change of labels
 // may make pending pods with matching affinity terms schedulable.
-func (p *PriorityQueue) AssignedPodUpdated(pod *v1.Pod) {
+func (p *PriorityQueue) AssignedPodUpdated(logger klog.Logger, pod *v1.Pod) {
 	p.lock.Lock()
 	if isPodResourcesResizedDown(pod) {
-		p.moveAllToActiveOrBackoffQueue(AssignedPodUpdate, nil)
+		p.moveAllToActiveOrBackoffQueue(logger, AssignedPodUpdate, nil)
 	} else {
-		p.movePodsToActiveOrBackoffQueue(p.getUnschedulablePodsWithMatchingAffinityTerm(pod), AssignedPodUpdate)
+		p.movePodsToActiveOrBackoffQueue(logger, p.getUnschedulablePodsWithMatchingAffinityTerm(pod), AssignedPodUpdate)
 	}
 	p.lock.Unlock()
 }
@@ -744,28 +749,28 @@ func (p *PriorityQueue) AssignedPodUpdated(pod *v1.Pod) {
 // This function adds all pods and then signals the condition variable to ensure that
 // if Pop() is waiting for an item, it receives the signal after all the pods are in the
 // queue and the head is the highest priority pod.
-func (p *PriorityQueue) moveAllToActiveOrBackoffQueue(event framework.ClusterEvent, preCheck PreEnqueueCheck) {
+func (p *PriorityQueue) moveAllToActiveOrBackoffQueue(logger klog.Logger, event framework.ClusterEvent, preCheck PreEnqueueCheck) {
 	unschedulablePods := make([]*framework.QueuedPodInfo, 0, len(p.unschedulablePods.podInfoMap))
 	for _, pInfo := range p.unschedulablePods.podInfoMap {
 		if preCheck == nil || preCheck(pInfo.Pod) {
 			unschedulablePods = append(unschedulablePods, pInfo)
 		}
 	}
-	p.movePodsToActiveOrBackoffQueue(unschedulablePods, event)
+	p.movePodsToActiveOrBackoffQueue(logger, unschedulablePods, event)
 }
 
 // MoveAllToActiveOrBackoffQueue moves all pods from unschedulablePods to activeQ or backoffQ.
 // This function adds all pods and then signals the condition variable to ensure that
 // if Pop() is waiting for an item, it receives the signal after all the pods are in the
 // queue and the head is the highest priority pod.
-func (p *PriorityQueue) MoveAllToActiveOrBackoffQueue(event framework.ClusterEvent, preCheck PreEnqueueCheck) {
+func (p *PriorityQueue) MoveAllToActiveOrBackoffQueue(logger klog.Logger, event framework.ClusterEvent, preCheck PreEnqueueCheck) {
 	p.lock.Lock()
 	defer p.lock.Unlock()
-	p.moveAllToActiveOrBackoffQueue(event, preCheck)
+	p.moveAllToActiveOrBackoffQueue(logger, event, preCheck)
 }
 
 // NOTE: this function assumes lock has been acquired in caller
-func (p *PriorityQueue) movePodsToActiveOrBackoffQueue(podInfoList []*framework.QueuedPodInfo, event framework.ClusterEvent) {
+func (p *PriorityQueue) movePodsToActiveOrBackoffQueue(logger klog.Logger, podInfoList []*framework.QueuedPodInfo, event framework.ClusterEvent) {
 	activated := false
 	for _, pInfo := range podInfoList {
 		// If the event doesn't help making the Pod schedulable, continue.
@@ -778,16 +783,16 @@ func (p *PriorityQueue) movePodsToActiveOrBackoffQueue(podInfoList []*framework.
 		pod := pInfo.Pod
 		if p.isPodBackingoff(pInfo) {
 			if err := p.podBackoffQ.Add(pInfo); err != nil {
-				klog.ErrorS(err, "Error adding pod to the backoff queue", "pod", klog.KObj(pod))
+				logger.Error(err, "Error adding pod to the backoff queue", "pod", klog.KObj(pod))
 			} else {
-				klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", event, "queue", backoffQName)
+				logger.V(5).Info("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", event, "queue", backoffQName)
 				metrics.SchedulerQueueIncomingPods.WithLabelValues("backoff", event.Label).Inc()
 				p.unschedulablePods.delete(pod, pInfo.Gated)
 			}
 		} else {
 			gated := pInfo.Gated
-			if added, _ := p.addToActiveQ(pInfo); added {
+			if added, _ := p.addToActiveQ(logger, pInfo); added {
-				klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", event, "queue", activeQName)
+				logger.V(5).Info("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", event, "queue", activeQName)
 				activated = true
 				metrics.SchedulerQueueIncomingPods.WithLabelValues("active", event.Label).Inc()
 				p.unschedulablePods.delete(pod, gated)
@@ -864,9 +869,9 @@ func (npm *nominator) deleteNominatedPodIfExistsUnlocked(pod *v1.Pod) {
 // This is called during the preemption process after a node is nominated to run
 // the pod. We update the structure before sending a request to update the pod
 // object to avoid races with the following scheduling cycles.
-func (npm *nominator) AddNominatedPod(pi *framework.PodInfo, nominatingInfo *framework.NominatingInfo) {
+func (npm *nominator) AddNominatedPod(logger klog.Logger, pi *framework.PodInfo, nominatingInfo *framework.NominatingInfo) {
 	npm.lock.Lock()
-	npm.addNominatedPodUnlocked(pi, nominatingInfo)
+	npm.addNominatedPodUnlocked(logger, pi, nominatingInfo)
 	npm.lock.Unlock()
 }
 
@@ -1019,7 +1024,7 @@ type nominator struct {
 	lock sync.RWMutex
 }
 
-func (npm *nominator) addNominatedPodUnlocked(pi *framework.PodInfo, nominatingInfo *framework.NominatingInfo) {
+func (npm *nominator) addNominatedPodUnlocked(logger klog.Logger, pi *framework.PodInfo, nominatingInfo *framework.NominatingInfo) {
 	// Always delete the pod if it already exists, to ensure we never store more than
 	// one instance of the pod.
 	npm.delete(pi.Pod)
@@ -1038,11 +1043,11 @@ func (npm *nominator) addNominatedPodUnlocked(pi *framework.PodInfo, nominatingI
 		// If the pod was removed or if it was already scheduled, don't nominate it.
 		updatedPod, err := npm.podLister.Pods(pi.Pod.Namespace).Get(pi.Pod.Name)
 		if err != nil {
-			klog.V(4).InfoS("Pod doesn't exist in podLister, aborted adding it to the nominator", "pod", klog.KObj(pi.Pod))
+			logger.V(4).Info("Pod doesn't exist in podLister, aborted adding it to the nominator", "pod", klog.KObj(pi.Pod))
 			return
 		}
 		if updatedPod.Spec.NodeName != "" {
-			klog.V(4).InfoS("Pod is already scheduled to a node, aborted adding it to the nominator", "pod", klog.KObj(pi.Pod), "node", updatedPod.Spec.NodeName)
+			logger.V(4).Info("Pod is already scheduled to a node, aborted adding it to the nominator", "pod", klog.KObj(pi.Pod), "node", updatedPod.Spec.NodeName)
 			return
 		}
 	}
@@ -1050,7 +1055,7 @@ func (npm *nominator) addNominatedPodUnlocked(pi *framework.PodInfo, nominatingI
 	npm.nominatedPodToNode[pi.Pod.UID] = nodeName
 	for _, npi := range npm.nominatedPods[nodeName] {
 		if npi.Pod.UID == pi.Pod.UID {
-			klog.V(4).InfoS("Pod already exists in the nominator", "pod", klog.KObj(npi.Pod))
+			logger.V(4).Info("Pod already exists in the nominator", "pod", klog.KObj(npi.Pod))
 			return
 		}
 	}
@@ -1075,13 +1080,13 @@ func (npm *nominator) delete(p *v1.Pod) {
 }
 
 // UpdateNominatedPod updates the <oldPod> with <newPod>.
-func (npm *nominator) UpdateNominatedPod(oldPod *v1.Pod, newPodInfo *framework.PodInfo) {
+func (npm *nominator) UpdateNominatedPod(logger klog.Logger, oldPod *v1.Pod, newPodInfo *framework.PodInfo) {
 	npm.lock.Lock()
 	defer npm.lock.Unlock()
-	npm.updateNominatedPodUnlocked(oldPod, newPodInfo)
+	npm.updateNominatedPodUnlocked(logger, oldPod, newPodInfo)
 }
 
-func (npm *nominator) updateNominatedPodUnlocked(oldPod *v1.Pod, newPodInfo *framework.PodInfo) {
+func (npm *nominator) updateNominatedPodUnlocked(logger klog.Logger, oldPod *v1.Pod, newPodInfo *framework.PodInfo) {
 	// In some cases, an Update event with no "NominatedNode" present is received right
 	// after a node("NominatedNode") is reserved for this pod in memory.
 	// In this case, we need to keep reserving the NominatedNode when updating the pod pointer.
@@ -1102,7 +1107,7 @@ func (npm *nominator) updateNominatedPodUnlocked(oldPod *v1.Pod, newPodInfo *fra
 	// We update irrespective of the nominatedNodeName changed or not, to ensure
 	// that pod pointer is updated.
 	npm.delete(oldPod)
-	npm.addNominatedPodUnlocked(newPodInfo, nominatingInfo)
+	npm.addNominatedPodUnlocked(logger, newPodInfo, nominatingInfo)
 }
 
 // NewPodNominator creates a nominator as a backing of framework.PodNominator.
@@ -1122,17 +1127,17 @@ func newPodNominator(podLister listersv1.PodLister) *nominator {
 
 // MakeNextPodFunc returns a function to retrieve the next pod from a given
 // scheduling queue
-func MakeNextPodFunc(queue SchedulingQueue) func() *framework.QueuedPodInfo {
+func MakeNextPodFunc(logger klog.Logger, queue SchedulingQueue) func() *framework.QueuedPodInfo {
 	return func() *framework.QueuedPodInfo {
 		podInfo, err := queue.Pop()
 		if err == nil {
-			klog.V(4).InfoS("About to try and schedule pod", "pod", klog.KObj(podInfo.Pod))
+			logger.V(4).Info("About to try and schedule pod", "pod", klog.KObj(podInfo.Pod))
 			for plugin := range podInfo.UnschedulablePlugins {
 				metrics.UnschedulableReason(plugin, podInfo.Pod.Spec.SchedulerName).Dec()
 			}
 			return podInfo
 		}
-		klog.ErrorS(err, "Error while retrieving next pod from scheduling queue")
+		logger.Error(err, "Error while retrieving next pod from scheduling queue")
 		return nil
 	}
 }

pkg/scheduler/internal/queue/scheduling_queue_test.go

@@ -36,6 +36,8 @@ import (
 	"k8s.io/client-go/informers"
 	"k8s.io/client-go/kubernetes/fake"
 	"k8s.io/component-base/metrics/testutil"
+	"k8s.io/klog/v2"
+	"k8s.io/klog/v2/ktesting"
 	podutil "k8s.io/kubernetes/pkg/api/v1/pod"
 	"k8s.io/kubernetes/pkg/scheduler/framework"
 	"k8s.io/kubernetes/pkg/scheduler/framework/plugins/queuesort"
@@ -93,16 +95,17 @@ func getUnschedulablePod(p *PriorityQueue, pod *v1.Pod) *v1.Pod {
 
 func TestPriorityQueue_Add(t *testing.T) {
 	objs := []runtime.Object{medPriorityPodInfo.Pod, unschedulablePodInfo.Pod, highPriorityPodInfo.Pod}
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueueWithObjects(ctx, newDefaultQueueSort(), objs)
-	if err := q.Add(medPriorityPodInfo.Pod); err != nil {
+	if err := q.Add(logger, medPriorityPodInfo.Pod); err != nil {
 		t.Errorf("add failed: %v", err)
 	}
-	if err := q.Add(unschedulablePodInfo.Pod); err != nil {
+	if err := q.Add(logger, unschedulablePodInfo.Pod); err != nil {
 		t.Errorf("add failed: %v", err)
 	}
-	if err := q.Add(highPriorityPodInfo.Pod); err != nil {
+	if err := q.Add(logger, highPriorityPodInfo.Pod); err != nil {
 		t.Errorf("add failed: %v", err)
 	}
 	expectedNominatedPods := &nominator{
@@ -138,13 +141,14 @@ func newDefaultQueueSort() framework.LessFunc {
 
 func TestPriorityQueue_AddWithReversePriorityLessFunc(t *testing.T) {
 	objs := []runtime.Object{medPriorityPodInfo.Pod, highPriorityPodInfo.Pod}
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueueWithObjects(ctx, newDefaultQueueSort(), objs)
-	if err := q.Add(medPriorityPodInfo.Pod); err != nil {
+	if err := q.Add(logger, medPriorityPodInfo.Pod); err != nil {
 		t.Errorf("add failed: %v", err)
 	}
-	if err := q.Add(highPriorityPodInfo.Pod); err != nil {
+	if err := q.Add(logger, highPriorityPodInfo.Pod); err != nil {
 		t.Errorf("add failed: %v", err)
 	}
 	if p, err := q.Pop(); err != nil || p.Pod != highPriorityPodInfo.Pod {
@@ -157,12 +161,13 @@ func TestPriorityQueue_AddWithReversePriorityLessFunc(t *testing.T) {
 
 func TestPriorityQueue_AddUnschedulableIfNotPresent(t *testing.T) {
 	objs := []runtime.Object{highPriNominatedPodInfo.Pod, unschedulablePodInfo.Pod}
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueueWithObjects(ctx, newDefaultQueueSort(), objs)
-	q.Add(highPriNominatedPodInfo.Pod)
+	q.Add(logger, highPriNominatedPodInfo.Pod)
-	q.AddUnschedulableIfNotPresent(newQueuedPodInfoForLookup(highPriNominatedPodInfo.Pod), q.SchedulingCycle()) // Must not add anything.
+	q.AddUnschedulableIfNotPresent(logger, newQueuedPodInfoForLookup(highPriNominatedPodInfo.Pod), q.SchedulingCycle()) // Must not add anything.
-	q.AddUnschedulableIfNotPresent(newQueuedPodInfoForLookup(unschedulablePodInfo.Pod), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, newQueuedPodInfoForLookup(unschedulablePodInfo.Pod), q.SchedulingCycle())
 	expectedNominatedPods := &nominator{
 		nominatedPodToNode: map[types.UID]string{
 			unschedulablePodInfo.Pod.UID:    "node1",
@@ -191,7 +196,8 @@ func TestPriorityQueue_AddUnschedulableIfNotPresent(t *testing.T) {
 // Pods in and before current scheduling cycle will be put back to activeQueue
 // if we were trying to schedule them when we received move request.
 func TestPriorityQueue_AddUnschedulableIfNotPresent_Backoff(t *testing.T) {
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(testingclock.NewFakeClock(time.Now())))
 	totalNum := 10
@@ -201,7 +207,7 @@ func TestPriorityQueue_AddUnschedulableIfNotPresent_Backoff(t *testing.T) {
 		p := st.MakePod().Name(fmt.Sprintf("pod%d", i)).Namespace(fmt.Sprintf("ns%d", i)).UID(fmt.Sprintf("upns%d", i)).Priority(priority).Obj()
 		expectedPods = append(expectedPods, *p)
 		// priority is to make pods ordered in the PriorityQueue
-		q.Add(p)
+		q.Add(logger, p)
 	}
 
 	// Pop all pods except for the first one
@@ -213,7 +219,7 @@ func TestPriorityQueue_AddUnschedulableIfNotPresent_Backoff(t *testing.T) {
 	}
 
 	// move all pods to active queue when we were trying to schedule them
-	q.MoveAllToActiveOrBackoffQueue(TestEvent, nil)
+	q.MoveAllToActiveOrBackoffQueue(logger, TestEvent, nil)
 	oldCycle := q.SchedulingCycle()
 
 	firstPod, _ := q.Pop()
@@ -234,7 +240,7 @@ func TestPriorityQueue_AddUnschedulableIfNotPresent_Backoff(t *testing.T) {
 			},
 		}
 
-		if err := q.AddUnschedulableIfNotPresent(newQueuedPodInfoForLookup(unschedulablePod), oldCycle); err != nil {
+		if err := q.AddUnschedulableIfNotPresent(logger, newQueuedPodInfoForLookup(unschedulablePod), oldCycle); err != nil {
 			t.Errorf("Failed to call AddUnschedulableIfNotPresent(%v): %v", unschedulablePod.Name, err)
 		}
 	}
@@ -250,7 +256,8 @@ func TestPriorityQueue_AddUnschedulableIfNotPresent_Backoff(t *testing.T) {
 
 func TestPriorityQueue_Pop(t *testing.T) {
 	objs := []runtime.Object{medPriorityPodInfo.Pod}
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueueWithObjects(ctx, newDefaultQueueSort(), objs)
 	wg := sync.WaitGroup{}
@@ -264,17 +271,18 @@ func TestPriorityQueue_Pop(t *testing.T) {
 			t.Errorf("Expected medPriorityPodInfo to be present in nomindatePods: %v", q.nominator.nominatedPods["node1"])
 		}
 	}()
-	q.Add(medPriorityPodInfo.Pod)
+	q.Add(logger, medPriorityPodInfo.Pod)
 	wg.Wait()
 }
 
 func TestPriorityQueue_Update(t *testing.T) {
 	objs := []runtime.Object{highPriorityPodInfo.Pod, unschedulablePodInfo.Pod, medPriorityPodInfo.Pod}
 	c := testingclock.NewFakeClock(time.Now())
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueueWithObjects(ctx, newDefaultQueueSort(), objs, WithClock(c))
-	q.Update(nil, highPriorityPodInfo.Pod)
+	q.Update(logger, nil, highPriorityPodInfo.Pod)
 	if _, exists, _ := q.activeQ.Get(newQueuedPodInfoForLookup(highPriorityPodInfo.Pod)); !exists {
 		t.Errorf("Expected %v to be added to activeQ.", highPriorityPodInfo.Pod.Name)
 	}
@@ -282,7 +290,7 @@ func TestPriorityQueue_Update(t *testing.T) {
 		t.Errorf("Expected nomindatePods to be empty: %v", q.nominator)
 	}
 	// Update highPriorityPodInfo and add a nominatedNodeName to it.
-	q.Update(highPriorityPodInfo.Pod, highPriNominatedPodInfo.Pod)
+	q.Update(logger, highPriorityPodInfo.Pod, highPriNominatedPodInfo.Pod)
 	if q.activeQ.Len() != 1 {
 		t.Error("Expected only one item in activeQ.")
 	}
@@ -291,12 +299,12 @@ func TestPriorityQueue_Update(t *testing.T) {
 	}
 	// Updating an unschedulable pod which is not in any of the two queues, should
 	// add the pod to activeQ.
-	q.Update(unschedulablePodInfo.Pod, unschedulablePodInfo.Pod)
+	q.Update(logger, unschedulablePodInfo.Pod, unschedulablePodInfo.Pod)
 	if _, exists, _ := q.activeQ.Get(newQueuedPodInfoForLookup(unschedulablePodInfo.Pod)); !exists {
 		t.Errorf("Expected %v to be added to activeQ.", unschedulablePodInfo.Pod.Name)
 	}
 	// Updating a pod that is already in activeQ, should not change it.
-	q.Update(unschedulablePodInfo.Pod, unschedulablePodInfo.Pod)
+	q.Update(logger, unschedulablePodInfo.Pod, unschedulablePodInfo.Pod)
 	if len(q.unschedulablePods.podInfoMap) != 0 {
 		t.Error("Expected unschedulablePods to be empty.")
 	}
@@ -313,7 +321,7 @@ func TestPriorityQueue_Update(t *testing.T) {
 	if err := q.podBackoffQ.Add(podInfo); err != nil {
 		t.Errorf("adding pod to backoff queue error: %v", err)
 	}
-	q.Update(podInfo.Pod, podInfo.Pod)
+	q.Update(logger, podInfo.Pod, podInfo.Pod)
 	rawPodInfo, err := q.podBackoffQ.Pop()
 	podGotFromBackoffQ := rawPodInfo.(*framework.QueuedPodInfo).Pod
 	if err != nil || podGotFromBackoffQ != medPriorityPodInfo.Pod {
@@ -322,13 +330,13 @@ func TestPriorityQueue_Update(t *testing.T) {
 
 	// updating a pod which is in unschedulable queue, and it is still backing off,
 	// we will move it to backoff queue
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(medPriorityPodInfo.Pod), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(medPriorityPodInfo.Pod), q.SchedulingCycle())
 	if len(q.unschedulablePods.podInfoMap) != 1 {
 		t.Error("Expected unschedulablePods to be 1.")
 	}
 	updatedPod := medPriorityPodInfo.Pod.DeepCopy()
 	updatedPod.Annotations["foo"] = "test"
-	q.Update(medPriorityPodInfo.Pod, updatedPod)
+	q.Update(logger, medPriorityPodInfo.Pod, updatedPod)
 	rawPodInfo, err = q.podBackoffQ.Pop()
 	podGotFromBackoffQ = rawPodInfo.(*framework.QueuedPodInfo).Pod
 	if err != nil || podGotFromBackoffQ != updatedPod {
@@ -337,7 +345,7 @@ func TestPriorityQueue_Update(t *testing.T) {
 
 	// updating a pod which is in unschedulable queue, and it is not backing off,
 	// we will move it to active queue
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(medPriorityPodInfo.Pod), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(medPriorityPodInfo.Pod), q.SchedulingCycle())
 	if len(q.unschedulablePods.podInfoMap) != 1 {
 		t.Error("Expected unschedulablePods to be 1.")
 	}
@@ -346,7 +354,7 @@ func TestPriorityQueue_Update(t *testing.T) {
 	// Move clock by podInitialBackoffDuration, so that pods in the unschedulablePods would pass the backing off,
 	// and the pods will be moved into activeQ.
 	c.Step(q.podInitialBackoffDuration)
-	q.Update(medPriorityPodInfo.Pod, updatedPod)
+	q.Update(logger, medPriorityPodInfo.Pod, updatedPod)
 	if p, err := q.Pop(); err != nil || p.Pod != updatedPod {
 		t.Errorf("Expected: %v after Pop, but got: %v", updatedPod.Name, p.Pod.Name)
 	}
@@ -354,11 +362,12 @@ func TestPriorityQueue_Update(t *testing.T) {
 
 func TestPriorityQueue_Delete(t *testing.T) {
 	objs := []runtime.Object{highPriorityPodInfo.Pod, unschedulablePodInfo.Pod}
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueueWithObjects(ctx, newDefaultQueueSort(), objs)
-	q.Update(highPriorityPodInfo.Pod, highPriNominatedPodInfo.Pod)
+	q.Update(logger, highPriorityPodInfo.Pod, highPriNominatedPodInfo.Pod)
-	q.Add(unschedulablePodInfo.Pod)
+	q.Add(logger, unschedulablePodInfo.Pod)
 	if err := q.Delete(highPriNominatedPodInfo.Pod); err != nil {
 		t.Errorf("delete failed: %v", err)
 	}
@@ -416,7 +425,8 @@ func TestPriorityQueue_Activate(t *testing.T) {
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
 			var objs []runtime.Object
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 			q := NewTestQueueWithObjects(ctx, newDefaultQueueSort(), objs)
 
@@ -434,7 +444,7 @@ func TestPriorityQueue_Activate(t *testing.T) {
 			}
 
 			// Activate specific pod according to the table
-			q.Activate(map[string]*v1.Pod{"test_pod": tt.qPodInfoToActivate.PodInfo.Pod})
+			q.Activate(logger, map[string]*v1.Pod{"test_pod": tt.qPodInfoToActivate.PodInfo.Pod})
 
 			// Check the result after activation by the length of activeQ
 			if wantLen := len(tt.want); q.activeQ.Len() != wantLen {
@@ -516,12 +526,13 @@ func TestPriorityQueue_addToActiveQ(t *testing.T) {
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
 			ctx, cancel := context.WithCancel(context.Background())
+			logger := klog.FromContext(ctx)
 			defer cancel()
 
 			m := map[string][]framework.PreEnqueuePlugin{"": tt.plugins}
 			q := NewTestQueueWithObjects(ctx, newDefaultQueueSort(), []runtime.Object{tt.pod}, WithPreEnqueuePluginMap(m),
 				WithPodInitialBackoffDuration(time.Second*30), WithPodMaxBackoffDuration(time.Second*60))
-			got, _ := q.addToActiveQ(q.newQueuedPodInfo(tt.pod))
+			got, _ := q.addToActiveQ(logger, q.newQueuedPodInfo(tt.pod))
 			if got != tt.wantSuccess {
 				t.Errorf("Unexpected result: want %v, but got %v", tt.wantSuccess, got)
 			}
@@ -532,7 +543,7 @@ func TestPriorityQueue_addToActiveQ(t *testing.T) {
 			// Simulate an update event.
 			clone := tt.pod.DeepCopy()
 			metav1.SetMetaDataAnnotation(&clone.ObjectMeta, "foo", "")
-			q.Update(tt.pod, clone)
+			q.Update(logger, tt.pod, clone)
 			// Ensure the pod is still located in unschedulablePods.
 			if tt.wantUnschedulablePods != len(q.unschedulablePods.podInfoMap) {
 				t.Errorf("Unexpected unschedulablePods: want %v, but got %v", tt.wantUnschedulablePods, len(q.unschedulablePods.podInfoMap))
@@ -595,6 +606,7 @@ func BenchmarkMoveAllToActiveOrBackoffQueue(b *testing.B) {
 	for _, tt := range tests {
 		for _, podsInUnschedulablePods := range []int{1000, 5000} {
 			b.Run(fmt.Sprintf("%v-%v", tt.name, podsInUnschedulablePods), func(b *testing.B) {
+				logger, _ := ktesting.NewTestContext(b)
 				for i := 0; i < b.N; i++ {
 					b.StopTimer()
 					c := testingclock.NewFakeClock(time.Now())
@@ -640,15 +652,15 @@ func BenchmarkMoveAllToActiveOrBackoffQueue(b *testing.B) {
 							// Random case.
 							podInfo = q.newQueuedPodInfo(p, plugins[j%len(plugins)])
 						}
-						q.AddUnschedulableIfNotPresent(podInfo, q.SchedulingCycle())
+						q.AddUnschedulableIfNotPresent(logger, podInfo, q.SchedulingCycle())
 					}
 
 					b.StartTimer()
 					if tt.moveEvent.Resource != "" {
-						q.MoveAllToActiveOrBackoffQueue(tt.moveEvent, nil)
+						q.MoveAllToActiveOrBackoffQueue(logger, tt.moveEvent, nil)
 					} else {
 						// Random case.
-						q.MoveAllToActiveOrBackoffQueue(events[i%len(events)], nil)
+						q.MoveAllToActiveOrBackoffQueue(logger, events[i%len(events)], nil)
 					}
 				}
 			})
@@ -661,22 +673,23 @@ func TestPriorityQueue_MoveAllToActiveOrBackoffQueue(t *testing.T) {
 	m := map[framework.ClusterEvent]sets.Set[string]{
 		{Resource: framework.Node, ActionType: framework.Add}: sets.New("fooPlugin"),
 	}
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(c), WithClusterEventMap(m))
-	q.Add(medPriorityPodInfo.Pod)
+	q.Add(logger, medPriorityPodInfo.Pod)
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(unschedulablePodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(unschedulablePodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(highPriorityPodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(highPriorityPodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
 	// Construct a Pod, but don't associate its scheduler failure to any plugin
 	hpp1 := highPriorityPodInfo.Pod.DeepCopy()
 	hpp1.Name = "hpp1"
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(hpp1), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(hpp1), q.SchedulingCycle())
 	// Construct another Pod, and associate its scheduler failure to plugin "barPlugin".
 	hpp2 := highPriorityPodInfo.Pod.DeepCopy()
 	hpp2.Name = "hpp2"
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(hpp2, "barPlugin"), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(hpp2, "barPlugin"), q.SchedulingCycle())
 	// Pods is still backing off, move the pod into backoffQ.
-	q.MoveAllToActiveOrBackoffQueue(NodeAdd, nil)
+	q.MoveAllToActiveOrBackoffQueue(logger, NodeAdd, nil)
 	if q.activeQ.Len() != 1 {
 		t.Errorf("Expected 1 item to be in activeQ, but got: %v", q.activeQ.Len())
 	}
@@ -691,9 +704,9 @@ func TestPriorityQueue_MoveAllToActiveOrBackoffQueue(t *testing.T) {
 	}
 
 	q.schedulingCycle++
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(unschedulablePodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(unschedulablePodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(highPriorityPodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(highPriorityPodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(hpp1), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(hpp1), q.SchedulingCycle())
 	for _, pod := range []*v1.Pod{unschedulablePodInfo.Pod, highPriorityPodInfo.Pod, hpp1, hpp2} {
 		if q.unschedulablePods.get(pod) == nil {
 			t.Errorf("Expected %v in the unschedulablePods", pod.Name)
@@ -702,7 +715,7 @@ func TestPriorityQueue_MoveAllToActiveOrBackoffQueue(t *testing.T) {
 	// Move clock by podInitialBackoffDuration, so that pods in the unschedulablePods would pass the backing off,
 	// and the pods will be moved into activeQ.
 	c.Step(q.podInitialBackoffDuration)
-	q.MoveAllToActiveOrBackoffQueue(NodeAdd, nil)
+	q.MoveAllToActiveOrBackoffQueue(logger, NodeAdd, nil)
 	// hpp2 won't be moved regardless of its backoff timer.
 	if q.activeQ.Len() != 4 {
 		t.Errorf("Expected 4 items to be in activeQ, but got: %v", q.activeQ.Len())
@@ -716,24 +729,26 @@ func TestPriorityQueue_MoveAllToActiveOrBackoffQueue(t *testing.T) {
 // when a pod with pod affinity is in unschedulablePods and another pod with a
 // matching label is added, the unschedulable pod is moved to activeQ.
 func TestPriorityQueue_AssignedPodAdded(t *testing.T) {
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
+	defer cancel()
+
 	affinityPod := st.MakePod().Name("afp").Namespace("ns1").UID("upns1").Annotation("annot2", "val2").Priority(mediumPriority).NominatedNodeName("node1").PodAffinityExists("service", "region", st.PodAffinityWithRequiredReq).Obj()
 	labelPod := st.MakePod().Name("lbp").Namespace(affinityPod.Namespace).Label("service", "securityscan").Node("node1").Obj()
 
 	c := testingclock.NewFakeClock(time.Now())
 	m := map[framework.ClusterEvent]sets.Set[string]{AssignedPodAdd: sets.New("fakePlugin")}
-	ctx, cancel := context.WithCancel(context.Background())
-	defer cancel()
 	q := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(c), WithClusterEventMap(m))
-	q.Add(medPriorityPodInfo.Pod)
+	q.Add(logger, medPriorityPodInfo.Pod)
 	// Add a couple of pods to the unschedulablePods.
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(unschedulablePodInfo.Pod, "fakePlugin"), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(unschedulablePodInfo.Pod, "fakePlugin"), q.SchedulingCycle())
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(affinityPod, "fakePlugin"), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(affinityPod, "fakePlugin"), q.SchedulingCycle())
 
 	// Move clock to make the unschedulable pods complete backoff.
 	c.Step(DefaultPodInitialBackoffDuration + time.Second)
 	// Simulate addition of an assigned pod. The pod has matching labels for
 	// affinityPod. So, affinityPod should go to activeQ.
-	q.AssignedPodAdded(labelPod)
+	q.AssignedPodAdded(logger, labelPod)
 	if getUnschedulablePod(q, affinityPod) != nil {
 		t.Error("affinityPod is still in the unschedulablePods.")
 	}
@@ -748,12 +763,13 @@ func TestPriorityQueue_AssignedPodAdded(t *testing.T) {
 
 func TestPriorityQueue_NominatedPodsForNode(t *testing.T) {
 	objs := []runtime.Object{medPriorityPodInfo.Pod, unschedulablePodInfo.Pod, highPriorityPodInfo.Pod}
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueueWithObjects(ctx, newDefaultQueueSort(), objs)
-	q.Add(medPriorityPodInfo.Pod)
+	q.Add(logger, medPriorityPodInfo.Pod)
-	q.Add(unschedulablePodInfo.Pod)
+	q.Add(logger, unschedulablePodInfo.Pod)
-	q.Add(highPriorityPodInfo.Pod)
+	q.Add(logger, highPriorityPodInfo.Pod)
 	if p, err := q.Pop(); err != nil || p.Pod != highPriorityPodInfo.Pod {
 		t.Errorf("Expected: %v after Pop, but got: %v", highPriorityPodInfo.Pod.Name, p.Pod.Name)
 	}
@@ -798,6 +814,7 @@ func TestPriorityQueue_NominatedPodDeleted(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
+			logger, _ := ktesting.NewTestContext(t)
 			cs := fake.NewSimpleClientset(tt.podInfo.Pod)
 			informerFactory := informers.NewSharedInformerFactory(cs, 0)
 			podLister := informerFactory.Core().V1().Pods().Lister()
@@ -814,7 +831,7 @@ func TestPriorityQueue_NominatedPodDeleted(t *testing.T) {
 				informerFactory.Core().V1().Pods().Informer().GetStore().Delete(tt.podInfo.Pod)
 			}
 
-			q.AddNominatedPod(tt.podInfo, nil)
+			q.AddNominatedPod(logger, tt.podInfo, nil)
 
 			if got := len(q.NominatedPodsForNode(tt.podInfo.Pod.Status.NominatedNodeName)) == 1; got != tt.want {
 				t.Errorf("Want %v, but got %v", tt.want, got)
@@ -832,12 +849,13 @@ func TestPriorityQueue_PendingPods(t *testing.T) {
 		return pendingSet
 	}
 
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueue(ctx, newDefaultQueueSort())
-	q.Add(medPriorityPodInfo.Pod)
+	q.Add(logger, medPriorityPodInfo.Pod)
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(unschedulablePodInfo.Pod), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(unschedulablePodInfo.Pod), q.SchedulingCycle())
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(highPriorityPodInfo.Pod), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(highPriorityPodInfo.Pod), q.SchedulingCycle())
 
 	expectedSet := makeSet([]*v1.Pod{medPriorityPodInfo.Pod, unschedulablePodInfo.Pod, highPriorityPodInfo.Pod})
 	gotPods, gotSummary := q.PendingPods()
@@ -848,7 +866,7 @@ func TestPriorityQueue_PendingPods(t *testing.T) {
 		t.Errorf("Unexpected pending pods summary: want %v, but got %v.", wantSummary, gotSummary)
 	}
 	// Move all to active queue. We should still see the same set of pods.
-	q.MoveAllToActiveOrBackoffQueue(TestEvent, nil)
+	q.MoveAllToActiveOrBackoffQueue(logger, TestEvent, nil)
 	gotPods, gotSummary = q.PendingPods()
 	if !reflect.DeepEqual(expectedSet, makeSet(gotPods)) {
 		t.Error("Unexpected list of pending Pods.")
@@ -859,19 +877,20 @@ func TestPriorityQueue_PendingPods(t *testing.T) {
 }
 
 func TestPriorityQueue_UpdateNominatedPodForNode(t *testing.T) {
-	objs := []runtime.Object{medPriorityPodInfo.Pod, unschedulablePodInfo.Pod, highPriorityPodInfo.Pod, scheduledPodInfo.Pod}
+	logger, ctx := ktesting.NewTestContext(t)
-	ctx, cancel := context.WithCancel(context.Background())
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
+	objs := []runtime.Object{medPriorityPodInfo.Pod, unschedulablePodInfo.Pod, highPriorityPodInfo.Pod, scheduledPodInfo.Pod}
 	q := NewTestQueueWithObjects(ctx, newDefaultQueueSort(), objs)
-	if err := q.Add(medPriorityPodInfo.Pod); err != nil {
+	if err := q.Add(logger, medPriorityPodInfo.Pod); err != nil {
 		t.Errorf("add failed: %v", err)
 	}
 	// Update unschedulablePodInfo on a different node than specified in the pod.
-	q.AddNominatedPod(mustNewTestPodInfo(t, unschedulablePodInfo.Pod),
+	q.AddNominatedPod(logger, mustNewTestPodInfo(t, unschedulablePodInfo.Pod),
 		&framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "node5"})
 
 	// Update nominated node name of a pod on a node that is not specified in the pod object.
-	q.AddNominatedPod(mustNewTestPodInfo(t, highPriorityPodInfo.Pod),
+	q.AddNominatedPod(logger, mustNewTestPodInfo(t, highPriorityPodInfo.Pod),
 		&framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "node2"})
 	expectedNominatedPods := &nominator{
 		nominatedPodToNode: map[types.UID]string{
@@ -897,7 +916,7 @@ func TestPriorityQueue_UpdateNominatedPodForNode(t *testing.T) {
 	}
 	// Update one of the nominated pods that doesn't have nominatedNodeName in the
 	// pod object. It should be updated correctly.
-	q.AddNominatedPod(highPriorityPodInfo, &framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "node4"})
+	q.AddNominatedPod(logger, highPriorityPodInfo, &framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "node4"})
 	expectedNominatedPods = &nominator{
 		nominatedPodToNode: map[types.UID]string{
 			medPriorityPodInfo.Pod.UID:   "node1",
@@ -916,7 +935,7 @@ func TestPriorityQueue_UpdateNominatedPodForNode(t *testing.T) {
 
 	// Attempt to nominate a pod that was deleted from the informer cache.
 	// Nothing should change.
-	q.AddNominatedPod(nonExistentPodInfo, &framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "node1"})
+	q.AddNominatedPod(logger, nonExistentPodInfo, &framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "node1"})
 	if diff := cmp.Diff(q.nominator, expectedNominatedPods, nominatorCmpOpts...); diff != "" {
 		t.Errorf("Unexpected diff after nominating a deleted pod (-want, +got):\n%s", diff)
 	}
@@ -924,7 +943,7 @@ func TestPriorityQueue_UpdateNominatedPodForNode(t *testing.T) {
 	// Nothing should change.
 	scheduledPodCopy := scheduledPodInfo.Pod.DeepCopy()
 	scheduledPodInfo.Pod.Spec.NodeName = ""
-	q.AddNominatedPod(mustNewTestPodInfo(t, scheduledPodCopy), &framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "node1"})
+	q.AddNominatedPod(logger, mustNewTestPodInfo(t, scheduledPodCopy), &framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "node1"})
 	if diff := cmp.Diff(q.nominator, expectedNominatedPods, nominatorCmpOpts...); diff != "" {
 		t.Errorf("Unexpected diff after nominating a scheduled pod (-want, +got):\n%s", diff)
 	}
@@ -1104,13 +1123,14 @@ func TestSchedulingQueue_Close(t *testing.T) {
 // are frequent events that move pods to the active queue.
 func TestRecentlyTriedPodsGoBack(t *testing.T) {
 	c := testingclock.NewFakeClock(time.Now())
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(c))
 	// Add a few pods to priority queue.
 	for i := 0; i < 5; i++ {
 		p := st.MakePod().Name(fmt.Sprintf("test-pod-%v", i)).Namespace("ns1").UID(fmt.Sprintf("tp00%v", i)).Priority(highPriority).Node("node1").NominatedNodeName("node1").Obj()
-		q.Add(p)
+		q.Add(logger, p)
 	}
 	c.Step(time.Microsecond)
 	// Simulate a pod being popped by the scheduler, determined unschedulable, and
@@ -1128,10 +1148,10 @@ func TestRecentlyTriedPodsGoBack(t *testing.T) {
 		LastProbeTime: metav1.Now(),
 	})
 	// Put in the unschedulable queue.
-	q.AddUnschedulableIfNotPresent(p1, q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, p1, q.SchedulingCycle())
 	c.Step(DefaultPodInitialBackoffDuration)
 	// Move all unschedulable pods to the active queue.
-	q.MoveAllToActiveOrBackoffQueue(UnschedulableTimeout, nil)
+	q.MoveAllToActiveOrBackoffQueue(logger, UnschedulableTimeout, nil)
 	// Simulation is over. Now let's pop all pods. The pod popped first should be
 	// the last one we pop here.
 	for i := 0; i < 5; i++ {
@@ -1151,7 +1171,8 @@ func TestRecentlyTriedPodsGoBack(t *testing.T) {
 // are frequent events that move pods to the active queue.
 func TestPodFailedSchedulingMultipleTimesDoesNotBlockNewerPod(t *testing.T) {
 	c := testingclock.NewFakeClock(time.Now())
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(c))
 
@@ -1169,11 +1190,11 @@ func TestPodFailedSchedulingMultipleTimesDoesNotBlockNewerPod(t *testing.T) {
 	})
 
 	// Put in the unschedulable queue
-	q.AddUnschedulableIfNotPresent(newQueuedPodInfoForLookup(unschedulablePod), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, newQueuedPodInfoForLookup(unschedulablePod), q.SchedulingCycle())
 	// Move clock to make the unschedulable pods complete backoff.
 	c.Step(DefaultPodInitialBackoffDuration + time.Second)
 	// Move all unschedulable pods to the active queue.
-	q.MoveAllToActiveOrBackoffQueue(UnschedulableTimeout, nil)
+	q.MoveAllToActiveOrBackoffQueue(logger, UnschedulableTimeout, nil)
 
 	// Simulate a pod being popped by the scheduler,
 	// At this time, unschedulable pod should be popped.
@@ -1188,7 +1209,7 @@ func TestPodFailedSchedulingMultipleTimesDoesNotBlockNewerPod(t *testing.T) {
 	// Assume newer pod was added just after unschedulable pod
 	// being popped and before being pushed back to the queue.
 	newerPod := st.MakePod().Name("test-newer-pod").Namespace("ns1").UID("tp002").CreationTimestamp(metav1.Now()).Priority(highPriority).NominatedNodeName("node1").Obj()
-	q.Add(newerPod)
+	q.Add(logger, newerPod)
 
 	// And then unschedulablePodInfo was determined as unschedulable AGAIN.
 	podutil.UpdatePodCondition(&unschedulablePod.Status, &v1.PodCondition{
@@ -1199,11 +1220,11 @@ func TestPodFailedSchedulingMultipleTimesDoesNotBlockNewerPod(t *testing.T) {
 	})
 
 	// And then, put unschedulable pod to the unschedulable queue
-	q.AddUnschedulableIfNotPresent(newQueuedPodInfoForLookup(unschedulablePod), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, newQueuedPodInfoForLookup(unschedulablePod), q.SchedulingCycle())
 	// Move clock to make the unschedulable pods complete backoff.
 	c.Step(DefaultPodInitialBackoffDuration + time.Second)
 	// Move all unschedulable pods to the active queue.
-	q.MoveAllToActiveOrBackoffQueue(UnschedulableTimeout, nil)
+	q.MoveAllToActiveOrBackoffQueue(logger, UnschedulableTimeout, nil)
 
 	// At this time, newerPod should be popped
 	// because it is the oldest tried pod.
@@ -1219,14 +1240,15 @@ func TestPodFailedSchedulingMultipleTimesDoesNotBlockNewerPod(t *testing.T) {
 // TestHighPriorityBackoff tests that a high priority pod does not block
 // other pods if it is unschedulable
 func TestHighPriorityBackoff(t *testing.T) {
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueue(ctx, newDefaultQueueSort())
 
 	midPod := st.MakePod().Name("test-midpod").Namespace("ns1").UID("tp-mid").Priority(midPriority).NominatedNodeName("node1").Obj()
 	highPod := st.MakePod().Name("test-highpod").Namespace("ns1").UID("tp-high").Priority(highPriority).NominatedNodeName("node1").Obj()
-	q.Add(midPod)
+	q.Add(logger, midPod)
-	q.Add(highPod)
+	q.Add(logger, highPod)
 	// Simulate a pod being popped by the scheduler, determined unschedulable, and
 	// then moved back to the active queue.
 	p, err := q.Pop()
@@ -1244,9 +1266,9 @@ func TestHighPriorityBackoff(t *testing.T) {
 		Message: "fake scheduling failure",
 	})
 	// Put in the unschedulable queue.
-	q.AddUnschedulableIfNotPresent(p, q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, p, q.SchedulingCycle())
 	// Move all unschedulable pods to the active queue.
-	q.MoveAllToActiveOrBackoffQueue(TestEvent, nil)
+	q.MoveAllToActiveOrBackoffQueue(logger, TestEvent, nil)
 
 	p, err = q.Pop()
 	if err != nil {
@@ -1264,7 +1286,8 @@ func TestHighPriorityFlushUnschedulablePodsLeftover(t *testing.T) {
 	m := map[framework.ClusterEvent]sets.Set[string]{
 		NodeAdd: sets.New("fakePlugin"),
 	}
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(c), WithClusterEventMap(m))
 	midPod := st.MakePod().Name("test-midpod").Namespace("ns1").UID("tp-mid").Priority(midPriority).NominatedNodeName("node1").Obj()
@@ -1286,10 +1309,10 @@ func TestHighPriorityFlushUnschedulablePodsLeftover(t *testing.T) {
 		Message: "fake scheduling failure",
 	})
 
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(highPod, "fakePlugin"), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(highPod, "fakePlugin"), q.SchedulingCycle())
-	q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(midPod, "fakePlugin"), q.SchedulingCycle())
+	q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(midPod, "fakePlugin"), q.SchedulingCycle())
 	c.Step(DefaultPodMaxInUnschedulablePodsDuration + time.Second)
-	q.flushUnschedulablePodsLeftover()
+	q.flushUnschedulablePodsLeftover(logger)
 
 	if p, err := q.Pop(); err != nil || p.Pod != highPod {
 		t.Errorf("Expected: %v after Pop, but got: %v", highPriorityPodInfo.Pod.Name, p.Pod.Name)
@@ -1345,7 +1368,8 @@ func TestPriorityQueue_initPodMaxInUnschedulablePodsDuration(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 			var queue *PriorityQueue
 			if test.podMaxInUnschedulablePodsDuration > 0 {
@@ -1360,7 +1384,7 @@ func TestPriorityQueue_initPodMaxInUnschedulablePodsDuration(t *testing.T) {
 			var podInfoList []*framework.QueuedPodInfo
 
 			for i, op := range test.operations {
-				op(queue, test.operands[i])
+				op(logger, queue, test.operands[i])
 			}
 
 			expectedLen := len(test.expected)
@@ -1383,25 +1407,25 @@ func TestPriorityQueue_initPodMaxInUnschedulablePodsDuration(t *testing.T) {
 	}
 }
 
-type operation func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo)
+type operation func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo)
 
 var (
-	add = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
+	add = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
-		queue.Add(pInfo.Pod)
+		queue.Add(logger, pInfo.Pod)
 	}
-	addUnschedulablePodBackToUnschedulablePods = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
+	addUnschedulablePodBackToUnschedulablePods = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
-		queue.AddUnschedulableIfNotPresent(pInfo, 0)
+		queue.AddUnschedulableIfNotPresent(logger, pInfo, 0)
 	}
-	addUnschedulablePodBackToBackoffQ = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
+	addUnschedulablePodBackToBackoffQ = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
-		queue.AddUnschedulableIfNotPresent(pInfo, -1)
+		queue.AddUnschedulableIfNotPresent(logger, pInfo, -1)
 	}
-	addPodActiveQ = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
+	addPodActiveQ = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
 		queue.activeQ.Add(pInfo)
 	}
-	updatePodActiveQ = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
+	updatePodActiveQ = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
 		queue.activeQ.Update(pInfo)
 	}
-	addPodUnschedulablePods = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
+	addPodUnschedulablePods = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
 		if !pInfo.Gated {
 			// Update pod condition to unschedulable.
 			podutil.UpdatePodCondition(&pInfo.Pod.Status, &v1.PodCondition{
@@ -1413,30 +1437,30 @@ var (
 		}
 		queue.unschedulablePods.addOrUpdate(pInfo)
 	}
-	deletePod = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
+	deletePod = func(_ klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
 		queue.Delete(pInfo.Pod)
 	}
-	updatePodQueueable = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
+	updatePodQueueable = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
 		newPod := pInfo.Pod.DeepCopy()
 		newPod.Labels = map[string]string{"queueable": ""}
-		queue.Update(pInfo.Pod, newPod)
+		queue.Update(logger, pInfo.Pod, newPod)
 	}
-	addPodBackoffQ = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
+	addPodBackoffQ = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
 		queue.podBackoffQ.Add(pInfo)
 	}
-	moveAllToActiveOrBackoffQ = func(queue *PriorityQueue, _ *framework.QueuedPodInfo) {
+	moveAllToActiveOrBackoffQ = func(logger klog.Logger, queue *PriorityQueue, _ *framework.QueuedPodInfo) {
-		queue.MoveAllToActiveOrBackoffQueue(UnschedulableTimeout, nil)
+		queue.MoveAllToActiveOrBackoffQueue(logger, UnschedulableTimeout, nil)
 	}
-	flushBackoffQ = func(queue *PriorityQueue, _ *framework.QueuedPodInfo) {
+	flushBackoffQ = func(logger klog.Logger, queue *PriorityQueue, _ *framework.QueuedPodInfo) {
 		queue.clock.(*testingclock.FakeClock).Step(2 * time.Second)
-		queue.flushBackoffQCompleted()
+		queue.flushBackoffQCompleted(logger)
 	}
-	moveClockForward = func(queue *PriorityQueue, _ *framework.QueuedPodInfo) {
+	moveClockForward = func(logger klog.Logger, queue *PriorityQueue, _ *framework.QueuedPodInfo) {
 		queue.clock.(*testingclock.FakeClock).Step(2 * time.Second)
 	}
-	flushUnschedulerQ = func(queue *PriorityQueue, _ *framework.QueuedPodInfo) {
+	flushUnschedulerQ = func(logger klog.Logger, queue *PriorityQueue, _ *framework.QueuedPodInfo) {
 		queue.clock.(*testingclock.FakeClock).Step(queue.podMaxInUnschedulablePodsDuration)
-		queue.flushUnschedulablePodsLeftover()
+		queue.flushUnschedulablePodsLeftover(logger)
 	}
 )
 
@@ -1505,13 +1529,14 @@ func TestPodTimestamp(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 			queue := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(testingclock.NewFakeClock(timestamp)))
 			var podInfoList []*framework.QueuedPodInfo
 
 			for i, op := range test.operations {
-				op(queue, test.operands[i])
+				op(logger, queue, test.operands[i])
 			}
 
 			expectedLen := len(test.expected)
@@ -1788,7 +1813,8 @@ scheduler_plugin_execution_duration_seconds_count{extension_point="PreEnqueue",p
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
 			resetMetrics()
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 
 			m := map[string][]framework.PreEnqueuePlugin{"": {&preEnqueuePlugin{allowlists: []string{queueable}}}}
@@ -1796,7 +1822,7 @@ scheduler_plugin_execution_duration_seconds_count{extension_point="PreEnqueue",p
 			queue := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(testingclock.NewFakeClock(timestamp)), WithPreEnqueuePluginMap(m), WithPluginMetricsSamplePercent(test.pluginMetricsSamplePercent), WithMetricsRecorder(*recorder))
 			for i, op := range test.operations {
 				for _, pInfo := range test.operands[i] {
-					op(queue, pInfo)
+					op(logger, queue, pInfo)
 				}
 			}
 
@@ -1818,10 +1844,11 @@ func TestPerPodSchedulingMetrics(t *testing.T) {
 	// Case 1: A pod is created and scheduled after 1 attempt. The queue operations are
 	// Add -> Pop.
 	c := testingclock.NewFakeClock(timestamp)
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	queue := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(c))
-	queue.Add(pod)
+	queue.Add(logger, pod)
 	pInfo, err := queue.Pop()
 	if err != nil {
 		t.Fatalf("Failed to pop a pod %v", err)
@@ -1832,16 +1859,16 @@ func TestPerPodSchedulingMetrics(t *testing.T) {
 	// Add -> Pop -> AddUnschedulableIfNotPresent -> flushUnschedulablePodsLeftover -> Pop.
 	c = testingclock.NewFakeClock(timestamp)
 	queue = NewTestQueue(ctx, newDefaultQueueSort(), WithClock(c))
-	queue.Add(pod)
+	queue.Add(logger, pod)
 	pInfo, err = queue.Pop()
 	if err != nil {
 		t.Fatalf("Failed to pop a pod %v", err)
 	}
-	queue.AddUnschedulableIfNotPresent(pInfo, 1)
+	queue.AddUnschedulableIfNotPresent(logger, pInfo, 1)
 	// Override clock to exceed the DefaultPodMaxInUnschedulablePodsDuration so that unschedulable pods
 	// will be moved to activeQ
 	c.SetTime(timestamp.Add(DefaultPodMaxInUnschedulablePodsDuration + 1))
-	queue.flushUnschedulablePodsLeftover()
+	queue.flushUnschedulablePodsLeftover(logger)
 	pInfo, err = queue.Pop()
 	if err != nil {
 		t.Fatalf("Failed to pop a pod %v", err)
@@ -1852,19 +1879,19 @@ func TestPerPodSchedulingMetrics(t *testing.T) {
 	// Add -> Pop -> AddUnschedulableIfNotPresent -> flushUnschedulablePodsLeftover -> Update -> Pop.
 	c = testingclock.NewFakeClock(timestamp)
 	queue = NewTestQueue(ctx, newDefaultQueueSort(), WithClock(c))
-	queue.Add(pod)
+	queue.Add(logger, pod)
 	pInfo, err = queue.Pop()
 	if err != nil {
 		t.Fatalf("Failed to pop a pod %v", err)
 	}
-	queue.AddUnschedulableIfNotPresent(pInfo, 1)
+	queue.AddUnschedulableIfNotPresent(logger, pInfo, 1)
 	// Override clock to exceed the DefaultPodMaxInUnschedulablePodsDuration so that unschedulable pods
 	// will be moved to activeQ
 	c.SetTime(timestamp.Add(DefaultPodMaxInUnschedulablePodsDuration + 1))
-	queue.flushUnschedulablePodsLeftover()
+	queue.flushUnschedulablePodsLeftover(logger)
 	newPod := pod.DeepCopy()
 	newPod.Generation = 1
-	queue.Update(pod, newPod)
+	queue.Update(logger, pod, newPod)
 	pInfo, err = queue.Pop()
 	if err != nil {
 		t.Fatalf("Failed to pop a pod %v", err)
@@ -1944,12 +1971,13 @@ func TestIncomingPodsMetrics(t *testing.T) {
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
 			metrics.SchedulerQueueIncomingPods.Reset()
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 			queue := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(testingclock.NewFakeClock(timestamp)))
 			for _, op := range test.operations {
 				for _, pInfo := range pInfos {
-					op(queue, pInfo)
+					op(logger, queue, pInfo)
 				}
 			}
 			metricName := metrics.SchedulerSubsystem + "_" + metrics.SchedulerQueueIncomingPods.Name
@@ -1972,7 +2000,8 @@ func checkPerPodSchedulingMetrics(name string, t *testing.T, pInfo *framework.Qu
 
 func TestBackOffFlow(t *testing.T) {
 	cl := testingclock.NewFakeClock(time.Now())
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	q := NewTestQueue(ctx, newDefaultQueueSort(), WithClock(cl))
 	steps := []struct {
@@ -1992,7 +2021,7 @@ func TestBackOffFlow(t *testing.T) {
 		Namespace: pod.Namespace,
 		Name:      pod.Name,
 	}
-	if err := q.Add(pod); err != nil {
+	if err := q.Add(logger, pod); err != nil {
 		t.Fatal(err)
 	}
 
@@ -2007,12 +2036,12 @@ func TestBackOffFlow(t *testing.T) {
 			if podInfo.Attempts != i+1 {
 				t.Errorf("got attempts %d, want %d", podInfo.Attempts, i+1)
 			}
-			if err := q.AddUnschedulableIfNotPresent(podInfo, int64(i)); err != nil {
+			if err := q.AddUnschedulableIfNotPresent(logger, podInfo, int64(i)); err != nil {
 				t.Fatal(err)
 			}
 
 			// An event happens.
-			q.MoveAllToActiveOrBackoffQueue(UnschedulableTimeout, nil)
+			q.MoveAllToActiveOrBackoffQueue(logger, UnschedulableTimeout, nil)
 
 			if _, ok, _ := q.podBackoffQ.Get(podInfo); !ok {
 				t.Errorf("pod %v is not in the backoff queue", podID)
@@ -2027,14 +2056,14 @@ func TestBackOffFlow(t *testing.T) {
 
 			// Simulate routine that continuously flushes the backoff queue.
 			cl.Step(time.Millisecond)
-			q.flushBackoffQCompleted()
+			q.flushBackoffQCompleted(logger)
 			// Still in backoff queue after an early flush.
 			if _, ok, _ := q.podBackoffQ.Get(podInfo); !ok {
 				t.Errorf("pod %v is not in the backoff queue", podID)
 			}
 			// Moved out of the backoff queue after timeout.
 			cl.Step(backoff)
-			q.flushBackoffQCompleted()
+			q.flushBackoffQCompleted(logger)
 			if _, ok, _ := q.podBackoffQ.Get(podInfo); ok {
 				t.Errorf("pod %v is still in the backoff queue", podID)
 			}
@@ -2183,11 +2212,12 @@ func TestMoveAllToActiveOrBackoffQueue_PreEnqueueChecks(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 			q := NewTestQueue(ctx, newDefaultQueueSort())
 			for i, podInfo := range tt.podInfos {
-				q.AddUnschedulableIfNotPresent(podInfo, q.schedulingCycle)
+				q.AddUnschedulableIfNotPresent(logger, podInfo, q.schedulingCycle)
 				// NOTE: On Windows, time.Now() is not as precise, 2 consecutive calls may return the same timestamp,
 				// resulting in 0 time delta / latency. This will cause the pods to be backed off in a random
 				// order, which would cause this test to fail, since the expectation is for them to be backed off
@@ -2195,7 +2225,7 @@ func TestMoveAllToActiveOrBackoffQueue_PreEnqueueChecks(t *testing.T) {
 				// See: https://github.com/golang/go/issues/8687
 				podInfo.Timestamp = podInfo.Timestamp.Add(time.Duration((i - len(tt.podInfos))) * time.Millisecond)
 			}
-			q.MoveAllToActiveOrBackoffQueue(TestEvent, tt.preEnqueueCheck)
+			q.MoveAllToActiveOrBackoffQueue(logger, TestEvent, tt.preEnqueueCheck)
 			var got []string
 			for q.podBackoffQ.Len() != 0 {
 				obj, err := q.podBackoffQ.Pop()

pkg/scheduler/schedule_one.go

@@ -60,6 +60,7 @@ const (
 
 // scheduleOne does the entire scheduling workflow for a single pod. It is serialized on the scheduling algorithm's host fitting.
 func (sched *Scheduler) scheduleOne(ctx context.Context) {
+	logger := klog.FromContext(ctx)
 	podInfo := sched.NextPod()
 	// pod could be nil when schedulerQueue is closed
 	if podInfo == nil || podInfo.Pod == nil {
@@ -70,14 +71,14 @@ func (sched *Scheduler) scheduleOne(ctx context.Context) {
 	if err != nil {
 		// This shouldn't happen, because we only accept for scheduling the pods
 		// which specify a scheduler name that matches one of the profiles.
-		klog.ErrorS(err, "Error occurred")
+		logger.Error(err, "Error occurred")
 		return
 	}
-	if sched.skipPodSchedule(fwk, pod) {
+	if sched.skipPodSchedule(ctx, fwk, pod) {
 		return
 	}
 
-	klog.V(3).InfoS("Attempting to schedule pod", "pod", klog.KObj(pod))
+	logger.V(3).Info("Attempting to schedule pod", "pod", klog.KObj(pod))
 
 	// Synchronously attempt to find a fit for the pod.
 	start := time.Now()
@@ -123,6 +124,7 @@ func (sched *Scheduler) schedulingCycle(
 	start time.Time,
 	podsToActivate *framework.PodsToActivate,
 ) (ScheduleResult, *framework.QueuedPodInfo, *framework.Status) {
+	logger := klog.FromContext(ctx)
 	pod := podInfo.Pod
 	scheduleResult, err := sched.SchedulePod(ctx, fwk, state, pod)
 	if err != nil {
@@ -133,7 +135,7 @@ func (sched *Scheduler) schedulingCycle(
 
 		fitError, ok := err.(*framework.FitError)
 		if !ok {
-			klog.ErrorS(err, "Error selecting node for pod", "pod", klog.KObj(pod))
+			logger.Error(err, "Error selecting node for pod", "pod", klog.KObj(pod))
 			return ScheduleResult{nominatingInfo: clearNominatedNode}, podInfo, framework.AsStatus(err)
 		}
 
@@ -143,7 +145,7 @@ func (sched *Scheduler) schedulingCycle(
 		// into the resources that were preempted, but this is harmless.
 
 		if !fwk.HasPostFilterPlugins() {
-			klog.V(3).InfoS("No PostFilter plugins are registered, so no preemption will be performed")
+			logger.V(3).Info("No PostFilter plugins are registered, so no preemption will be performed")
 			return ScheduleResult{}, podInfo, framework.NewStatus(framework.Unschedulable).WithError(err)
 		}
 
@@ -152,9 +154,9 @@ func (sched *Scheduler) schedulingCycle(
 		msg := status.Message()
 		fitError.Diagnosis.PostFilterMsg = msg
 		if status.Code() == framework.Error {
-			klog.ErrorS(nil, "Status after running PostFilter plugins for pod", "pod", klog.KObj(pod), "status", msg)
+			logger.Error(nil, "Status after running PostFilter plugins for pod", "pod", klog.KObj(pod), "status", msg)
 		} else {
-			klog.V(5).InfoS("Status after running PostFilter plugins for pod", "pod", klog.KObj(pod), "status", msg)
+			logger.V(5).Info("Status after running PostFilter plugins for pod", "pod", klog.KObj(pod), "status", msg)
 		}
 
 		var nominatingInfo *framework.NominatingInfo
@@ -170,7 +172,7 @@ func (sched *Scheduler) schedulingCycle(
 	assumedPodInfo := podInfo.DeepCopy()
 	assumedPod := assumedPodInfo.Pod
 	// assume modifies `assumedPod` by setting NodeName=scheduleResult.SuggestedHost
-	err = sched.assume(assumedPod, scheduleResult.SuggestedHost)
+	err = sched.assume(logger, assumedPod, scheduleResult.SuggestedHost)
 	if err != nil {
 		// This is most probably result of a BUG in retrying logic.
 		// We report an error here so that pod scheduling can be retried.
@@ -186,8 +188,8 @@ func (sched *Scheduler) schedulingCycle(
 	if sts := fwk.RunReservePluginsReserve(ctx, state, assumedPod, scheduleResult.SuggestedHost); !sts.IsSuccess() {
 		// trigger un-reserve to clean up state associated with the reserved Pod
 		fwk.RunReservePluginsUnreserve(ctx, state, assumedPod, scheduleResult.SuggestedHost)
-		if forgetErr := sched.Cache.ForgetPod(assumedPod); forgetErr != nil {
+		if forgetErr := sched.Cache.ForgetPod(logger, assumedPod); forgetErr != nil {
-			klog.ErrorS(forgetErr, "Scheduler cache ForgetPod failed")
+			logger.Error(forgetErr, "Scheduler cache ForgetPod failed")
 		}
 
 		return ScheduleResult{nominatingInfo: clearNominatedNode},
@@ -200,8 +202,8 @@ func (sched *Scheduler) schedulingCycle(
 	if !runPermitStatus.IsWait() && !runPermitStatus.IsSuccess() {
 		// trigger un-reserve to clean up state associated with the reserved Pod
 		fwk.RunReservePluginsUnreserve(ctx, state, assumedPod, scheduleResult.SuggestedHost)
-		if forgetErr := sched.Cache.ForgetPod(assumedPod); forgetErr != nil {
+		if forgetErr := sched.Cache.ForgetPod(logger, assumedPod); forgetErr != nil {
-			klog.ErrorS(forgetErr, "Scheduler cache ForgetPod failed")
+			logger.Error(forgetErr, "Scheduler cache ForgetPod failed")
 		}
 
 		return ScheduleResult{nominatingInfo: clearNominatedNode},
@@ -211,7 +213,7 @@ func (sched *Scheduler) schedulingCycle(
 
 	// At the end of a successful scheduling cycle, pop and move up Pods if needed.
 	if len(podsToActivate.Map) != 0 {
-		sched.SchedulingQueue.Activate(podsToActivate.Map)
+		sched.SchedulingQueue.Activate(logger, podsToActivate.Map)
 		// Clear the entries after activation.
 		podsToActivate.Map = make(map[string]*v1.Pod)
 	}
@@ -228,6 +230,7 @@ func (sched *Scheduler) bindingCycle(
 	assumedPodInfo *framework.QueuedPodInfo,
 	start time.Time,
 	podsToActivate *framework.PodsToActivate) *framework.Status {
+	logger := klog.FromContext(ctx)
 
 	assumedPod := assumedPodInfo.Pod
 
@@ -247,7 +250,7 @@ func (sched *Scheduler) bindingCycle(
 	}
 
 	// Calculating nodeResourceString can be heavy. Avoid it if klog verbosity is below 2.
-	klog.V(2).InfoS("Successfully bound pod to node", "pod", klog.KObj(assumedPod), "node", scheduleResult.SuggestedHost, "evaluatedNodes", scheduleResult.EvaluatedNodes, "feasibleNodes", scheduleResult.FeasibleNodes)
+	logger.V(2).Info("Successfully bound pod to node", "pod", klog.KObj(assumedPod), "node", scheduleResult.SuggestedHost, "evaluatedNodes", scheduleResult.EvaluatedNodes, "feasibleNodes", scheduleResult.FeasibleNodes)
 	metrics.PodScheduled(fwk.ProfileName(), metrics.SinceInSeconds(start))
 	metrics.PodSchedulingAttempts.Observe(float64(assumedPodInfo.Attempts))
 	metrics.PodSchedulingDuration.WithLabelValues(getAttemptsLabel(assumedPodInfo)).Observe(metrics.SinceInSeconds(assumedPodInfo.InitialAttemptTimestamp))
@@ -257,7 +260,7 @@ func (sched *Scheduler) bindingCycle(
 
 	// At the end of a successful binding cycle, move up Pods if needed.
 	if len(podsToActivate.Map) != 0 {
-		sched.SchedulingQueue.Activate(podsToActivate.Map)
+		sched.SchedulingQueue.Activate(logger, podsToActivate.Map)
 		// Unlike the logic in schedulingCycle(), we don't bother deleting the entries
 		// as `podsToActivate.Map` is no longer consumed.
 	}
@@ -273,12 +276,13 @@ func (sched *Scheduler) handleBindingCycleError(
 	start time.Time,
 	scheduleResult ScheduleResult,
 	status *framework.Status) {
+	logger := klog.FromContext(ctx)
 
 	assumedPod := podInfo.Pod
 	// trigger un-reserve plugins to clean up state associated with the reserved Pod
 	fwk.RunReservePluginsUnreserve(ctx, state, assumedPod, scheduleResult.SuggestedHost)
-	if forgetErr := sched.Cache.ForgetPod(assumedPod); forgetErr != nil {
+	if forgetErr := sched.Cache.ForgetPod(logger, assumedPod); forgetErr != nil {
-		klog.ErrorS(forgetErr, "scheduler cache ForgetPod failed")
+		logger.Error(forgetErr, "scheduler cache ForgetPod failed")
 	} else {
 		// "Forget"ing an assumed Pod in binding cycle should be treated as a PodDelete event,
 		// as the assumed Pod had occupied a certain amount of resources in scheduler cache.
@@ -287,11 +291,11 @@ func (sched *Scheduler) handleBindingCycleError(
 		// It's intentional to "defer" this operation; otherwise MoveAllToActiveOrBackoffQueue() would
 		// update `q.moveRequest` and thus move the assumed pod to backoffQ anyways.
 		if status.IsUnschedulable() {
-			defer sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(internalqueue.AssignedPodDelete, func(pod *v1.Pod) bool {
+			defer sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, internalqueue.AssignedPodDelete, func(pod *v1.Pod) bool {
 				return assumedPod.UID != pod.UID
 			})
 		} else {
-			sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(internalqueue.AssignedPodDelete, nil)
+			sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(logger, internalqueue.AssignedPodDelete, nil)
 		}
 	}
 
@@ -307,11 +311,11 @@ func (sched *Scheduler) frameworkForPod(pod *v1.Pod) (framework.Framework, error
 }
 
 // skipPodSchedule returns true if we could skip scheduling the pod for specified cases.
-func (sched *Scheduler) skipPodSchedule(fwk framework.Framework, pod *v1.Pod) bool {
+func (sched *Scheduler) skipPodSchedule(ctx context.Context, fwk framework.Framework, pod *v1.Pod) bool {
 	// Case 1: pod is being deleted.
 	if pod.DeletionTimestamp != nil {
 		fwk.EventRecorder().Eventf(pod, nil, v1.EventTypeWarning, "FailedScheduling", "Scheduling", "skip schedule deleting pod: %v/%v", pod.Namespace, pod.Name)
-		klog.V(3).InfoS("Skip schedule deleting pod", "pod", klog.KObj(pod))
+		klog.FromContext(ctx).V(3).Info("Skip schedule deleting pod", "pod", klog.KObj(pod))
 		return true
 	}
 
@@ -320,6 +324,7 @@ func (sched *Scheduler) skipPodSchedule(fwk framework.Framework, pod *v1.Pod) bo
 	// during its previous scheduling cycle but before getting assumed.
 	isAssumed, err := sched.Cache.IsAssumedPod(pod)
 	if err != nil {
+		// TODO(91633): pass ctx into a revised HandleError
 		utilruntime.HandleError(fmt.Errorf("failed to check whether pod %s/%s is assumed: %v", pod.Namespace, pod.Name, err))
 		return false
 	}
@@ -332,8 +337,7 @@ func (sched *Scheduler) skipPodSchedule(fwk framework.Framework, pod *v1.Pod) bo
 func (sched *Scheduler) schedulePod(ctx context.Context, fwk framework.Framework, state *framework.CycleState, pod *v1.Pod) (result ScheduleResult, err error) {
 	trace := utiltrace.New("Scheduling", utiltrace.Field{Key: "namespace", Value: pod.Namespace}, utiltrace.Field{Key: "name", Value: pod.Name})
 	defer trace.LogIfLong(100 * time.Millisecond)
-
+	if err := sched.Cache.UpdateSnapshot(klog.FromContext(ctx), sched.nodeInfoSnapshot); err != nil {
-	if err := sched.Cache.UpdateSnapshot(sched.nodeInfoSnapshot); err != nil {
 		return result, err
 	}
 	trace.Step("Snapshotting scheduler cache and node infos done")
@@ -383,6 +387,7 @@ func (sched *Scheduler) schedulePod(ctx context.Context, fwk framework.Framework
 // Filters the nodes to find the ones that fit the pod based on the framework
 // filter plugins and filter extenders.
 func (sched *Scheduler) findNodesThatFitPod(ctx context.Context, fwk framework.Framework, state *framework.CycleState, pod *v1.Pod) ([]*v1.Node, framework.Diagnosis, error) {
+	logger := klog.FromContext(ctx)
 	diagnosis := framework.Diagnosis{
 		NodeToStatusMap:      make(framework.NodeToStatusMap),
 		UnschedulablePlugins: sets.New[string](),
@@ -401,7 +406,7 @@ func (sched *Scheduler) findNodesThatFitPod(ctx context.Context, fwk framework.F
 		// Record the messages from PreFilter in Diagnosis.PreFilterMsg.
 		msg := s.Message()
 		diagnosis.PreFilterMsg = msg
-		klog.V(5).InfoS("Status after running PreFilter plugins for pod", "pod", klog.KObj(pod), "status", msg)
+		logger.V(5).Info("Status after running PreFilter plugins for pod", "pod", klog.KObj(pod), "status", msg)
 		// Status satisfying IsUnschedulable() gets injected into diagnosis.UnschedulablePlugins.
 		if s.FailedPlugin() != "" {
 			diagnosis.UnschedulablePlugins.Insert(s.FailedPlugin())
@@ -414,7 +419,7 @@ func (sched *Scheduler) findNodesThatFitPod(ctx context.Context, fwk framework.F
 	if len(pod.Status.NominatedNodeName) > 0 {
 		feasibleNodes, err := sched.evaluateNominatedNode(ctx, pod, fwk, state, diagnosis)
 		if err != nil {
-			klog.ErrorS(err, "Evaluation failed on nominated node", "pod", klog.KObj(pod), "node", pod.Status.NominatedNodeName)
+			logger.Error(err, "Evaluation failed on nominated node", "pod", klog.KObj(pod), "node", pod.Status.NominatedNodeName)
 		}
 		// Nominated node passes all the filters, scheduler is good to assign this node to the pod.
 		if len(feasibleNodes) != 0 {
@@ -442,7 +447,7 @@ func (sched *Scheduler) findNodesThatFitPod(ctx context.Context, fwk framework.F
 		return nil, diagnosis, err
 	}
 
-	feasibleNodes, err = findNodesThatPassExtenders(sched.Extenders, pod, feasibleNodes, diagnosis.NodeToStatusMap)
+	feasibleNodes, err = findNodesThatPassExtenders(ctx, sched.Extenders, pod, feasibleNodes, diagnosis.NodeToStatusMap)
 	if err != nil {
 		return nil, diagnosis, err
 	}
@@ -461,7 +466,7 @@ func (sched *Scheduler) evaluateNominatedNode(ctx context.Context, pod *v1.Pod,
 		return nil, err
 	}
 
-	feasibleNodes, err = findNodesThatPassExtenders(sched.Extenders, pod, feasibleNodes, diagnosis.NodeToStatusMap)
+	feasibleNodes, err = findNodesThatPassExtenders(ctx, sched.Extenders, pod, feasibleNodes, diagnosis.NodeToStatusMap)
 	if err != nil {
 		return nil, err
 	}
@@ -571,7 +576,8 @@ func (sched *Scheduler) numFeasibleNodesToFind(percentageOfNodesToScore *int32,
 	return numNodes
 }
 
-func findNodesThatPassExtenders(extenders []framework.Extender, pod *v1.Pod, feasibleNodes []*v1.Node, statuses framework.NodeToStatusMap) ([]*v1.Node, error) {
+func findNodesThatPassExtenders(ctx context.Context, extenders []framework.Extender, pod *v1.Pod, feasibleNodes []*v1.Node, statuses framework.NodeToStatusMap) ([]*v1.Node, error) {
+	logger := klog.FromContext(ctx)
 	// Extenders are called sequentially.
 	// Nodes in original feasibleNodes can be excluded in one extender, and pass on to the next
 	// extender in a decreasing manner.
@@ -591,7 +597,7 @@ func findNodesThatPassExtenders(extenders []framework.Extender, pod *v1.Pod, fea
 		feasibleList, failedMap, failedAndUnresolvableMap, err := extender.Filter(pod, feasibleNodes)
 		if err != nil {
 			if extender.IsIgnorable() {
-				klog.InfoS("Skipping extender as it returned error and has ignorable flag set", "extender", extender, "err", err)
+				logger.Info("Skipping extender as it returned error and has ignorable flag set", "extender", extender, "err", err)
 				continue
 			}
 			return nil, err
@@ -637,6 +643,7 @@ func prioritizeNodes(
 	pod *v1.Pod,
 	nodes []*v1.Node,
 ) ([]framework.NodePluginScores, error) {
+	logger := klog.FromContext(ctx)
 	// If no priority configs are provided, then all nodes will have a score of one.
 	// This is required to generate the priority list in the required format
 	if len(extenders) == 0 && !fwk.HasScorePlugins() {
@@ -663,11 +670,11 @@ func prioritizeNodes(
 	}
 
 	// Additional details logged at level 10 if enabled.
-	klogV := klog.V(10)
+	loggerVTen := logger.V(10)
-	if klogV.Enabled() {
+	if loggerVTen.Enabled() {
 		for _, nodeScore := range nodesScores {
 			for _, pluginScore := range nodeScore.Scores {
-				klogV.InfoS("Plugin scored node for pod", "pod", klog.KObj(pod), "plugin", pluginScore.Name, "node", nodeScore.Name, "score", pluginScore.Score)
+				loggerVTen.Info("Plugin scored node for pod", "pod", klog.KObj(pod), "plugin", pluginScore.Name, "node", nodeScore.Name, "score", pluginScore.Score)
 			}
 		}
 	}
@@ -692,7 +699,7 @@ func prioritizeNodes(
 				prioritizedList, weight, err := extenders[extIndex].Prioritize(pod, nodes)
 				if err != nil {
 					// Prioritization errors from extender can be ignored, let k8s/other extenders determine the priorities
-					klog.V(5).InfoS("Failed to run extender's priority function. No score given by this extender.", "error", err, "pod", klog.KObj(pod), "extender", extenders[extIndex].Name())
+					logger.V(5).Info("Failed to run extender's priority function. No score given by this extender.", "error", err, "pod", klog.KObj(pod), "extender", extenders[extIndex].Name())
 					return
 				}
 				mu.Lock()
@@ -700,8 +707,8 @@ func prioritizeNodes(
 				for i := range *prioritizedList {
 					nodename := (*prioritizedList)[i].Host
 					score := (*prioritizedList)[i].Score
-					if klogV.Enabled() {
+					if loggerVTen.Enabled() {
-						klogV.InfoS("Extender scored node for pod", "pod", klog.KObj(pod), "extender", extenders[extIndex].Name(), "node", nodename, "score", score)
+						loggerVTen.Info("Extender scored node for pod", "pod", klog.KObj(pod), "extender", extenders[extIndex].Name(), "node", nodename, "score", score)
 					}
 
 					// MaxExtenderPriority may diverge from the max priority used in the scheduler and defined by MaxNodeScore,
@@ -732,9 +739,9 @@ func prioritizeNodes(
 		}
 	}
 
-	if klogV.Enabled() {
+	if loggerVTen.Enabled() {
 		for i := range nodesScores {
-			klogV.InfoS("Calculated node's final score for pod", "pod", klog.KObj(pod), "node", nodesScores[i].Name, "score", nodesScores[i].TotalScore)
+			loggerVTen.Info("Calculated node's final score for pod", "pod", klog.KObj(pod), "node", nodesScores[i].Name, "score", nodesScores[i].TotalScore)
 		}
 	}
 	return nodesScores, nil
@@ -767,15 +774,15 @@ func selectHost(nodeScores []framework.NodePluginScores) (string, error) {
 
 // assume signals to the cache that a pod is already in the cache, so that binding can be asynchronous.
 // assume modifies `assumed`.
-func (sched *Scheduler) assume(assumed *v1.Pod, host string) error {
+func (sched *Scheduler) assume(logger klog.Logger, assumed *v1.Pod, host string) error {
 	// Optimistically assume that the binding will succeed and send it to apiserver
 	// in the background.
 	// If the binding fails, scheduler will release resources allocated to assumed pod
 	// immediately.
 	assumed.Spec.NodeName = host
 
-	if err := sched.Cache.AssumePod(assumed); err != nil {
+	if err := sched.Cache.AssumePod(logger, assumed); err != nil {
-		klog.ErrorS(err, "Scheduler cache AssumePod failed")
+		logger.Error(err, "Scheduler cache AssumePod failed")
 		return err
 	}
 	// if "assumed" is a nominated pod, we should remove it from internal cache
@@ -790,8 +797,9 @@ func (sched *Scheduler) assume(assumed *v1.Pod, host string) error {
 // The precedence for binding is: (1) extenders and (2) framework plugins.
 // We expect this to run asynchronously, so we handle binding metrics internally.
 func (sched *Scheduler) bind(ctx context.Context, fwk framework.Framework, assumed *v1.Pod, targetNode string, state *framework.CycleState) (status *framework.Status) {
+	logger := klog.FromContext(ctx)
 	defer func() {
-		sched.finishBinding(fwk, assumed, targetNode, status)
+		sched.finishBinding(logger, fwk, assumed, targetNode, status)
 	}()
 
 	bound, err := sched.extendersBinding(assumed, targetNode)
@@ -815,12 +823,12 @@ func (sched *Scheduler) extendersBinding(pod *v1.Pod, node string) (bool, error)
 	return false, nil
 }
 
-func (sched *Scheduler) finishBinding(fwk framework.Framework, assumed *v1.Pod, targetNode string, status *framework.Status) {
+func (sched *Scheduler) finishBinding(logger klog.Logger, fwk framework.Framework, assumed *v1.Pod, targetNode string, status *framework.Status) {
-	if finErr := sched.Cache.FinishBinding(assumed); finErr != nil {
+	if finErr := sched.Cache.FinishBinding(logger, assumed); finErr != nil {
-		klog.ErrorS(finErr, "Scheduler cache FinishBinding failed")
+		logger.Error(finErr, "Scheduler cache FinishBinding failed")
 	}
 	if !status.IsSuccess() {
-		klog.V(1).InfoS("Failed to bind pod", "pod", klog.KObj(assumed))
+		logger.V(1).Info("Failed to bind pod", "pod", klog.KObj(assumed))
 		return
 	}
 
@@ -839,6 +847,7 @@ func getAttemptsLabel(p *framework.QueuedPodInfo) string {
 // handleSchedulingFailure records an event for the pod that indicates the
 // pod has failed to schedule. Also, update the pod condition and nominated node name if set.
 func (sched *Scheduler) handleSchedulingFailure(ctx context.Context, fwk framework.Framework, podInfo *framework.QueuedPodInfo, status *framework.Status, nominatingInfo *framework.NominatingInfo, start time.Time) {
+	logger := klog.FromContext(ctx)
 	reason := v1.PodReasonSchedulerError
 	if status.IsUnschedulable() {
 		reason = v1.PodReasonUnschedulable
@@ -856,13 +865,13 @@ func (sched *Scheduler) handleSchedulingFailure(ctx context.Context, fwk framewo
 	errMsg := status.Message()
 
 	if err == ErrNoNodesAvailable {
-		klog.V(2).InfoS("Unable to schedule pod; no nodes are registered to the cluster; waiting", "pod", klog.KObj(pod), "err", err)
+
-	} else if fitError, ok := err.(*framework.FitError); ok {
+		logger.V(2).Info("Unable to schedule pod; no nodes are registered to the cluster; waiting", "pod", klog.KObj(pod))
-		// Inject UnschedulablePlugins to PodInfo, which will be used later for moving Pods between queues efficiently.
+	} else if fitError, ok := err.(*framework.FitError); ok { // Inject UnschedulablePlugins to PodInfo, which will be used later for moving Pods between queues efficiently.
 		podInfo.UnschedulablePlugins = fitError.Diagnosis.UnschedulablePlugins
-		klog.V(2).InfoS("Unable to schedule pod; no fit; waiting", "pod", klog.KObj(pod), "err", errMsg)
+		logger.V(2).Info("Unable to schedule pod; no fit; waiting", "pod", klog.KObj(pod), "err", errMsg)
 	} else if apierrors.IsNotFound(err) {
-		klog.V(2).InfoS("Unable to schedule pod, possibly due to node not found; waiting", "pod", klog.KObj(pod), "err", errMsg)
+		logger.V(2).Info("Unable to schedule pod, possibly due to node not found; waiting", "pod", klog.KObj(pod), "err", errMsg)
 		if errStatus, ok := err.(apierrors.APIStatus); ok && errStatus.Status().Details.Kind == "node" {
 			nodeName := errStatus.Status().Details.Name
 			// when node is not found, We do not remove the node right away. Trying again to get
@@ -870,32 +879,32 @@ func (sched *Scheduler) handleSchedulingFailure(ctx context.Context, fwk framewo
 			_, err := fwk.ClientSet().CoreV1().Nodes().Get(context.TODO(), nodeName, metav1.GetOptions{})
 			if err != nil && apierrors.IsNotFound(err) {
 				node := v1.Node{ObjectMeta: metav1.ObjectMeta{Name: nodeName}}
-				if err := sched.Cache.RemoveNode(&node); err != nil {
+				if err := sched.Cache.RemoveNode(logger, &node); err != nil {
-					klog.V(4).InfoS("Node is not found; failed to remove it from the cache", "node", node.Name)
+					logger.V(4).Info("Node is not found; failed to remove it from the cache", "node", node.Name)
 				}
 			}
 		}
 	} else {
-		klog.ErrorS(err, "Error scheduling pod; retrying", "pod", klog.KObj(pod))
+		logger.Error(err, "Error scheduling pod; retrying", "pod", klog.KObj(pod))
 	}
 
 	// Check if the Pod exists in informer cache.
 	podLister := fwk.SharedInformerFactory().Core().V1().Pods().Lister()
 	cachedPod, e := podLister.Pods(pod.Namespace).Get(pod.Name)
 	if e != nil {
-		klog.InfoS("Pod doesn't exist in informer cache", "pod", klog.KObj(pod), "err", e)
+		logger.Info("Pod doesn't exist in informer cache", "pod", klog.KObj(pod), "err", e)
 	} else {
 		// In the case of extender, the pod may have been bound successfully, but timed out returning its response to the scheduler.
 		// It could result in the live version to carry .spec.nodeName, and that's inconsistent with the internal-queued version.
 		if len(cachedPod.Spec.NodeName) != 0 {
-			klog.InfoS("Pod has been assigned to node. Abort adding it back to queue.", "pod", klog.KObj(pod), "node", cachedPod.Spec.NodeName)
+			logger.Info("Pod has been assigned to node. Abort adding it back to queue.", "pod", klog.KObj(pod), "node", cachedPod.Spec.NodeName)
 		} else {
 			// As <cachedPod> is from SharedInformer, we need to do a DeepCopy() here.
 			// ignore this err since apiserver doesn't properly validate affinity terms
 			// and we can't fix the validation for backwards compatibility.
 			podInfo.PodInfo, _ = framework.NewPodInfo(cachedPod.DeepCopy())
-			if err := sched.SchedulingQueue.AddUnschedulableIfNotPresent(podInfo, sched.SchedulingQueue.SchedulingCycle()); err != nil {
+			if err := sched.SchedulingQueue.AddUnschedulableIfNotPresent(logger, podInfo, sched.SchedulingQueue.SchedulingCycle()); err != nil {
-				klog.ErrorS(err, "Error occurred")
+				logger.Error(err, "Error occurred")
 			}
 		}
 	}
@@ -905,7 +914,8 @@ func (sched *Scheduler) handleSchedulingFailure(ctx context.Context, fwk framewo
 	// and the time the scheduler receives a Pod Update for the nominated pod.
 	// Here we check for nil only for tests.
 	if sched.SchedulingQueue != nil {
-		sched.SchedulingQueue.AddNominatedPod(podInfo.PodInfo, nominatingInfo)
+		logger := klog.FromContext(ctx)
+		sched.SchedulingQueue.AddNominatedPod(logger, podInfo.PodInfo, nominatingInfo)
 	}
 
 	if err == nil {
@@ -921,7 +931,7 @@ func (sched *Scheduler) handleSchedulingFailure(ctx context.Context, fwk framewo
 		Reason:  reason,
 		Message: errMsg,
 	}, nominatingInfo); err != nil {
-		klog.ErrorS(err, "Error updating pod", "pod", klog.KObj(pod))
+		klog.FromContext(ctx).Error(err, "Error updating pod", "pod", klog.KObj(pod))
 	}
 }
 
@@ -936,7 +946,8 @@ func truncateMessage(message string) string {
 }
 
 func updatePod(ctx context.Context, client clientset.Interface, pod *v1.Pod, condition *v1.PodCondition, nominatingInfo *framework.NominatingInfo) error {
-	klog.V(3).InfoS("Updating pod condition", "pod", klog.KObj(pod), "conditionType", condition.Type, "conditionStatus", condition.Status, "conditionReason", condition.Reason)
+	logger := klog.FromContext(ctx)
+	logger.V(3).Info("Updating pod condition", "pod", klog.KObj(pod), "conditionType", condition.Type, "conditionStatus", condition.Status, "conditionReason", condition.Reason)
 	podStatusCopy := pod.Status.DeepCopy()
 	// NominatedNodeName is updated only if we are trying to set it, and the value is
 	// different from the existing one.

pkg/scheduler/schedule_one_test.go

@@ -46,6 +46,8 @@ import (
 	clientcache "k8s.io/client-go/tools/cache"
 	"k8s.io/client-go/tools/events"
 	"k8s.io/component-helpers/storage/volume"
+	"k8s.io/klog/v2"
+	"k8s.io/klog/v2/ktesting"
 	extenderv1 "k8s.io/kube-scheduler/extender/v1"
 	schedulerapi "k8s.io/kubernetes/pkg/scheduler/apis/config"
 	"k8s.io/kubernetes/pkg/scheduler/framework"
@@ -811,13 +813,14 @@ func TestSchedulerScheduleOne(t *testing.T) {
 }
 
 func TestSchedulerNoPhantomPodAfterExpire(t *testing.T) {
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	queuedPodStore := clientcache.NewFIFO(clientcache.MetaNamespaceKeyFunc)
-	scache := internalcache.New(100*time.Millisecond, ctx.Done())
+	scache := internalcache.New(ctx, 100*time.Millisecond)
 	pod := podWithPort("pod.Name", "", 8080)
 	node := v1.Node{ObjectMeta: metav1.ObjectMeta{Name: "node1", UID: types.UID("node1")}}
-	scache.AddNode(&node)
+	scache.AddNode(logger, &node)
 
 	fns := []st.RegisterPluginFunc{
 		st.RegisterQueueSortPlugin(queuesort.Name, queuesort.New),
@@ -876,13 +879,14 @@ func TestSchedulerNoPhantomPodAfterExpire(t *testing.T) {
 }
 
 func TestSchedulerNoPhantomPodAfterDelete(t *testing.T) {
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	queuedPodStore := clientcache.NewFIFO(clientcache.MetaNamespaceKeyFunc)
-	scache := internalcache.New(10*time.Minute, ctx.Done())
+	scache := internalcache.New(ctx, 10*time.Minute)
 	firstPod := podWithPort("pod.Name", "", 8080)
 	node := v1.Node{ObjectMeta: metav1.ObjectMeta{Name: "node1", UID: types.UID("node1")}}
-	scache.AddNode(&node)
+	scache.AddNode(logger, &node)
 	fns := []st.RegisterPluginFunc{
 		st.RegisterQueueSortPlugin(queuesort.Name, queuesort.New),
 		st.RegisterBindPlugin(defaultbinder.Name, defaultbinder.New),
@@ -921,10 +925,10 @@ func TestSchedulerNoPhantomPodAfterDelete(t *testing.T) {
 	// and would be removed itself (without any explicit actions on schedulernodeinfo). Even in that case,
 	// explicitly AddPod will as well correct the behavior.
 	firstPod.Spec.NodeName = node.Name
-	if err := scache.AddPod(firstPod); err != nil {
+	if err := scache.AddPod(logger, firstPod); err != nil {
 		t.Fatalf("err: %v", err)
 	}
-	if err := scache.RemovePod(firstPod); err != nil {
+	if err := scache.RemovePod(logger, firstPod); err != nil {
 		t.Fatalf("err: %v", err)
 	}
 
@@ -945,10 +949,11 @@ func TestSchedulerNoPhantomPodAfterDelete(t *testing.T) {
 }
 
 func TestSchedulerFailedSchedulingReasons(t *testing.T) {
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 	queuedPodStore := clientcache.NewFIFO(clientcache.MetaNamespaceKeyFunc)
-	scache := internalcache.New(10*time.Minute, ctx.Done())
+	scache := internalcache.New(ctx, 10*time.Minute)
 
 	// Design the baseline for the pods, and we will make nodes that don't fit it later.
 	var cpu = int64(4)
@@ -980,7 +985,7 @@ func TestSchedulerFailedSchedulingReasons(t *testing.T) {
 					v1.ResourcePods:   *(resource.NewQuantity(10, resource.DecimalSI)),
 				}},
 		}
-		scache.AddNode(&node)
+		scache.AddNode(logger, &node)
 		nodes = append(nodes, &node)
 		objects = append(objects, &node)
 	}
@@ -1221,7 +1226,8 @@ func TestSchedulerBinding(t *testing.T) {
 				}
 				return false, nil, nil
 			})
-			ctx, cancel := context.WithCancel(context.Background())
+			_, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 			fwk, err := st.NewFramework(ctx,
 				[]st.RegisterPluginFunc{
@@ -1233,7 +1239,7 @@ func TestSchedulerBinding(t *testing.T) {
 			}
 			sched := &Scheduler{
 				Extenders:                test.extenders,
-				Cache:                    internalcache.New(100*time.Millisecond, ctx.Done()),
+				Cache:                    internalcache.New(ctx, 100*time.Millisecond),
 				nodeInfoSnapshot:         nil,
 				percentageOfNodesToScore: 0,
 			}
@@ -1660,13 +1666,14 @@ func TestFindNodesThatPassExtenders(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
+			_, ctx := ktesting.NewTestContext(t)
 			var extenders []framework.Extender
 			for ii := range tt.extenders {
 				extenders = append(extenders, &tt.extenders[ii])
 			}
 
 			pod := st.MakePod().Name("1").UID("1").Obj()
-			got, err := findNodesThatPassExtenders(extenders, pod, tt.nodes, tt.filteredNodesStatuses)
+			got, err := findNodesThatPassExtenders(ctx, extenders, pod, tt.nodes, tt.filteredNodesStatuses)
 			if tt.expectsErr {
 				if err == nil {
 					t.Error("Unexpected non-error")
@@ -2204,18 +2211,19 @@ func TestSchedulerSchedulePod(t *testing.T) {
 	}
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 
-			cache := internalcache.New(time.Duration(0), ctx.Done())
+			cache := internalcache.New(ctx, time.Duration(0))
 			for _, pod := range test.pods {
-				cache.AddPod(pod)
+				cache.AddPod(logger, pod)
 			}
 			var nodes []*v1.Node
 			for _, name := range test.nodes {
 				node := &v1.Node{ObjectMeta: metav1.ObjectMeta{Name: name, Labels: map[string]string{"hostname": name}}}
 				nodes = append(nodes, node)
-				cache.AddNode(node)
+				cache.AddNode(logger, node)
 			}
 
 			cs := clientsetfake.NewSimpleClientset()
@@ -2403,7 +2411,8 @@ func TestFindFitPredicateCallCounts(t *testing.T) {
 				registerFakeFilterFunc,
 				st.RegisterBindPlugin(defaultbinder.Name, defaultbinder.New),
 			}
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 			fwk, err := st.NewFramework(
 				ctx,
@@ -2415,11 +2424,14 @@ func TestFindFitPredicateCallCounts(t *testing.T) {
 			}
 
 			scheduler := makeScheduler(ctx, nodes)
-			if err := scheduler.Cache.UpdateSnapshot(scheduler.nodeInfoSnapshot); err != nil {
+			if err := scheduler.Cache.UpdateSnapshot(logger, scheduler.nodeInfoSnapshot); err != nil {
 				t.Fatal(err)
 			}
-			fwk.AddNominatedPod(mustNewPodInfo(t, st.MakePod().UID("nominated").Priority(midPriority).Obj()),
+			podinfo, err := framework.NewPodInfo(st.MakePod().UID("nominated").Priority(midPriority).Obj())
-				&framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "1"})
+			if err != nil {
+				t.Fatal(err)
+			}
+			fwk.AddNominatedPod(logger, podinfo, &framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "1"})
 
 			_, _, err = scheduler.findNodesThatFitPod(ctx, fwk, framework.NewCycleState(), test.pod)
 			if err != nil {
@@ -2952,16 +2964,17 @@ func TestPreferNominatedNodeFilterCallCounts(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 
 			// create three nodes in the cluster.
 			nodes := makeNodeList([]string{"node1", "node2", "node3"})
 			client := clientsetfake.NewSimpleClientset(test.pod)
 			informerFactory := informers.NewSharedInformerFactory(client, 0)
-			cache := internalcache.New(time.Duration(0), ctx.Done())
+			cache := internalcache.New(ctx, time.Duration(0))
 			for _, n := range nodes {
-				cache.AddNode(n)
+				cache.AddNode(logger, n)
 			}
 			plugin := st.FakeFilterPlugin{FailedNodeReturnCodeMap: test.nodeReturnCodeMap}
 			registerFakeFilterFunc := st.RegisterFilterPlugin(
@@ -3038,9 +3051,10 @@ func makeNodeList(nodeNames []string) []*v1.Node {
 
 // makeScheduler makes a simple Scheduler for testing.
 func makeScheduler(ctx context.Context, nodes []*v1.Node) *Scheduler {
-	cache := internalcache.New(time.Duration(0), ctx.Done())
+	logger := klog.FromContext(ctx)
+	cache := internalcache.New(ctx, time.Duration(0))
 	for _, n := range nodes {
-		cache.AddNode(n)
+		cache.AddNode(logger, n)
 	}
 
 	sched := &Scheduler{
@@ -3049,7 +3063,7 @@ func makeScheduler(ctx context.Context, nodes []*v1.Node) *Scheduler {
 		percentageOfNodesToScore: schedulerapi.DefaultPercentageOfNodesToScore,
 	}
 	sched.applyDefaultHandlers()
-	cache.UpdateSnapshot(sched.nodeInfoSnapshot)
+	cache.UpdateSnapshot(logger, sched.nodeInfoSnapshot)
 	return sched
 }
 
@@ -3162,6 +3176,7 @@ func setupTestScheduler(ctx context.Context, t *testing.T, queuedPodStore *clien
 }
 
 func setupTestSchedulerWithVolumeBinding(ctx context.Context, t *testing.T, volumeBinder volumebinding.SchedulerVolumeBinder, broadcaster events.EventBroadcaster) (*Scheduler, chan *v1.Binding, chan error) {
+	logger := klog.FromContext(ctx)
 	testNode := v1.Node{ObjectMeta: metav1.ObjectMeta{Name: "node1", UID: types.UID("node1")}}
 	queuedPodStore := clientcache.NewFIFO(clientcache.MetaNamespaceKeyFunc)
 	pod := podWithID("foo", "")
@@ -3169,8 +3184,8 @@ func setupTestSchedulerWithVolumeBinding(ctx context.Context, t *testing.T, volu
 	pod.Spec.Volumes = append(pod.Spec.Volumes, v1.Volume{Name: "testVol",
 		VolumeSource: v1.VolumeSource{PersistentVolumeClaim: &v1.PersistentVolumeClaimVolumeSource{ClaimName: "testPVC"}}})
 	queuedPodStore.Add(pod)
-	scache := internalcache.New(10*time.Minute, ctx.Done())
+	scache := internalcache.New(ctx, 10*time.Minute)
-	scache.AddNode(&testNode)
+	scache.AddNode(logger, &testNode)
 	testPVC := v1.PersistentVolumeClaim{ObjectMeta: metav1.ObjectMeta{Name: "testPVC", Namespace: pod.Namespace, UID: types.UID("testPVC")}}
 	client := clientsetfake.NewSimpleClientset(&testNode, &testPVC)
 	informerFactory := informers.NewSharedInformerFactory(client, 0)

pkg/scheduler/scheduler.go

@@ -96,6 +96,11 @@ type Scheduler struct {
 	percentageOfNodesToScore int32
 
 	nextStartNodeIndex int
+
+	// logger *must* be initialized when creating a Scheduler,
+	// otherwise logging functions will access a nil sink and
+	// panic.
+	logger klog.Logger
 }
 
 func (s *Scheduler) applyDefaultHandlers() {
@@ -246,6 +251,7 @@ func New(ctx context.Context,
 	recorderFactory profile.RecorderFactory,
 	opts ...Option) (*Scheduler, error) {
 
+	logger := klog.FromContext(ctx)
 	stopEverything := ctx.Done()
 
 	options := defaultSchedulerOptions
@@ -270,7 +276,7 @@ func New(ctx context.Context,
 
 	metrics.Register()
 
-	extenders, err := buildExtenders(options.extenders, options.profiles)
+	extenders, err := buildExtenders(logger, options.extenders, options.profiles)
 	if err != nil {
 		return nil, fmt.Errorf("couldn't build extenders: %w", err)
 	}
@@ -323,11 +329,11 @@ func New(ctx context.Context,
 		fwk.SetPodNominator(podQueue)
 	}
 
-	schedulerCache := internalcache.New(durationToExpireAssumedPod, stopEverything)
+	schedulerCache := internalcache.New(ctx, durationToExpireAssumedPod)
 
 	// Setup cache debugger.
 	debugger := cachedebugger.New(nodeLister, podLister, schedulerCache, podQueue)
-	debugger.ListenForSignal(stopEverything)
+	debugger.ListenForSignal(ctx)
 
 	sched := &Scheduler{
 		Cache:                    schedulerCache,
@@ -335,10 +341,11 @@ func New(ctx context.Context,
 		nodeInfoSnapshot:         snapshot,
 		percentageOfNodesToScore: options.percentageOfNodesToScore,
 		Extenders:                extenders,
-		NextPod:                  internalqueue.MakeNextPodFunc(podQueue),
+		NextPod:                  internalqueue.MakeNextPodFunc(logger, podQueue),
 		StopEverything:           stopEverything,
 		SchedulingQueue:          podQueue,
 		Profiles:                 profiles,
+		logger:                   logger,
 	}
 	sched.applyDefaultHandlers()
 
@@ -349,7 +356,8 @@ func New(ctx context.Context,
 
 // Run begins watching and scheduling. It starts scheduling and blocked until the context is done.
 func (sched *Scheduler) Run(ctx context.Context) {
-	sched.SchedulingQueue.Run()
+	logger := klog.FromContext(ctx)
+	sched.SchedulingQueue.Run(logger)
 
 	// We need to start scheduleOne loop in a dedicated goroutine,
 	// because scheduleOne function hangs on getting the next item
@@ -371,7 +379,7 @@ func NewInformerFactory(cs clientset.Interface, resyncPeriod time.Duration) info
 	return informerFactory
 }
 
-func buildExtenders(extenders []schedulerapi.Extender, profiles []schedulerapi.KubeSchedulerProfile) ([]framework.Extender, error) {
+func buildExtenders(logger klog.Logger, extenders []schedulerapi.Extender, profiles []schedulerapi.KubeSchedulerProfile) ([]framework.Extender, error) {
 	var fExtenders []framework.Extender
 	if len(extenders) == 0 {
 		return nil, nil
@@ -380,7 +388,7 @@ func buildExtenders(extenders []schedulerapi.Extender, profiles []schedulerapi.K
 	var ignoredExtendedResources []string
 	var ignorableExtenders []framework.Extender
 	for i := range extenders {
-		klog.V(2).InfoS("Creating extender", "extender", extenders[i])
+		logger.V(2).Info("Creating extender", "extender", extenders[i])
 		extender, err := NewHTTPExtender(&extenders[i])
 		if err != nil {
 			return nil, err

pkg/scheduler/scheduler_test.go

@@ -36,6 +36,7 @@ import (
 	"k8s.io/client-go/kubernetes/scheme"
 	"k8s.io/client-go/tools/cache"
 	"k8s.io/client-go/tools/events"
+	"k8s.io/klog/v2"
 	"k8s.io/klog/v2/ktesting"
 	schedulerapi "k8s.io/kubernetes/pkg/scheduler/apis/config"
 	"k8s.io/kubernetes/pkg/scheduler/framework"
@@ -262,7 +263,8 @@ func TestFailureHandler(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 
 			client := fake.NewSimpleClientset(&v1.PodList{Items: []v1.Pod{*testPod}})
@@ -272,14 +274,14 @@ func TestFailureHandler(t *testing.T) {
 			podInformer.Informer().GetStore().Add(testPod)
 
 			queue := internalqueue.NewPriorityQueue(nil, informerFactory, internalqueue.WithClock(testingclock.NewFakeClock(time.Now())))
-			schedulerCache := internalcache.New(30*time.Second, ctx.Done())
+			schedulerCache := internalcache.New(ctx, 30*time.Second)
 
-			queue.Add(testPod)
+			queue.Add(logger, testPod)
 			queue.Pop()
 
 			if tt.podUpdatedDuringScheduling {
 				podInformer.Informer().GetStore().Update(testPodUpdated)
-				queue.Update(testPod, testPodUpdated)
+				queue.Update(logger, testPod, testPodUpdated)
 			}
 			if tt.podDeletedDuringScheduling {
 				podInformer.Informer().GetStore().Delete(testPod)
@@ -340,7 +342,8 @@ func TestFailureHandler_NodeNotFound(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
-			ctx, cancel := context.WithCancel(context.Background())
+			logger, ctx := ktesting.NewTestContext(t)
+			ctx, cancel := context.WithCancel(ctx)
 			defer cancel()
 
 			client := fake.NewSimpleClientset(&v1.PodList{Items: []v1.Pod{*testPod}}, &v1.NodeList{Items: tt.nodes})
@@ -350,12 +353,12 @@ func TestFailureHandler_NodeNotFound(t *testing.T) {
 			podInformer.Informer().GetStore().Add(testPod)
 
 			queue := internalqueue.NewPriorityQueue(nil, informerFactory, internalqueue.WithClock(testingclock.NewFakeClock(time.Now())))
-			schedulerCache := internalcache.New(30*time.Second, ctx.Done())
+			schedulerCache := internalcache.New(ctx, 30*time.Second)
 
 			for i := range tt.nodes {
 				node := tt.nodes[i]
 				// Add node to schedulerCache no matter it's deleted in API server or not.
-				schedulerCache.AddNode(&node)
+				schedulerCache.AddNode(logger, &node)
 				if node.Name == tt.nodeNameToDelete {
 					client.CoreV1().Nodes().Delete(ctx, node.Name, metav1.DeleteOptions{})
 				}
@@ -382,7 +385,8 @@ func TestFailureHandler_NodeNotFound(t *testing.T) {
 }
 
 func TestFailureHandler_PodAlreadyBound(t *testing.T) {
-	ctx, cancel := context.WithCancel(context.Background())
+	logger, ctx := ktesting.NewTestContext(t)
+	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
 
 	nodeFoo := v1.Node{ObjectMeta: metav1.ObjectMeta{Name: "foo"}}
@@ -395,10 +399,10 @@ func TestFailureHandler_PodAlreadyBound(t *testing.T) {
 	podInformer.Informer().GetStore().Add(testPod)
 
 	queue := internalqueue.NewPriorityQueue(nil, informerFactory, internalqueue.WithClock(testingclock.NewFakeClock(time.Now())))
-	schedulerCache := internalcache.New(30*time.Second, ctx.Done())
+	schedulerCache := internalcache.New(ctx, 30*time.Second)
 
 	// Add node to schedulerCache no matter it's deleted in API server or not.
-	schedulerCache.AddNode(&nodeFoo)
+	schedulerCache.AddNode(logger, &nodeFoo)
 
 	s, fwk, err := initScheduler(ctx, schedulerCache, queue, client, informerFactory)
 	if err != nil {
@@ -488,6 +492,7 @@ func getPodFromPriorityQueue(queue *internalqueue.PriorityQueue, pod *v1.Pod) *v
 
 func initScheduler(ctx context.Context, cache internalcache.Cache, queue internalqueue.SchedulingQueue,
 	client kubernetes.Interface, informerFactory informers.SharedInformerFactory) (*Scheduler, framework.Framework, error) {
+	logger := klog.FromContext(ctx)
 	registerPluginFuncs := []st.RegisterPluginFunc{
 		st.RegisterQueueSortPlugin(queuesort.Name, queuesort.New),
 		st.RegisterBindPlugin(defaultbinder.Name, defaultbinder.New),
@@ -510,6 +515,7 @@ func initScheduler(ctx context.Context, cache internalcache.Cache, queue interna
 		StopEverything:  ctx.Done(),
 		SchedulingQueue: queue,
 		Profiles:        profile.Map{testSchedulerName: fwk},
+		logger:          logger,
 	}
 	s.applyDefaultHandlers()
 

test/integration/scheduler/queue_test.go

@@ -37,6 +37,7 @@ import (
 	"k8s.io/client-go/dynamic"
 	"k8s.io/client-go/kubernetes"
 	featuregatetesting "k8s.io/component-base/featuregate/testing"
+	"k8s.io/klog/v2"
 	configv1 "k8s.io/kube-scheduler/config/v1"
 	apiservertesting "k8s.io/kubernetes/cmd/kube-apiserver/app/testing"
 	"k8s.io/kubernetes/pkg/features"
@@ -378,6 +379,7 @@ func TestCustomResourceEnqueue(t *testing.T) {
 	defer testutils.CleanupTest(t, testCtx)
 
 	cs, ns, ctx := testCtx.ClientSet, testCtx.NS.Name, testCtx.Ctx
+	logger := klog.FromContext(ctx)
 	// Create one Node.
 	node := st.MakeNode().Name("fake-node").Obj()
 	if _, err := cs.CoreV1().Nodes().Create(ctx, node, metav1.CreateOptions{}); err != nil {
@@ -415,7 +417,7 @@ func TestCustomResourceEnqueue(t *testing.T) {
 
 	// Scheduling cycle is incremented from 0 to 1 after NextPod() is called, so
 	// pass a number larger than 1 to move Pod to unschedulablePods.
-	testCtx.Scheduler.SchedulingQueue.AddUnschedulableIfNotPresent(podInfo, 10)
+	testCtx.Scheduler.SchedulingQueue.AddUnschedulableIfNotPresent(logger, podInfo, 10)
 
 	// Trigger a Custom Resource event.
 	// We expect this event to trigger moving the test Pod from unschedulablePods to activeQ.