github/kubernetes
4
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Merge pull request #116849 from mengjiao-liu/contextual-logging-scheduler-internal

Browse Source 
scheduler: update the scheduler interface and cache methods to use contextual logging
This commit is contained in:
Kubernetes Prow Robot
2023-05-29 11:29:43 -07:00
committed by GitHub
parent a6f641b656 074900e81b
commit 94d0bd2405
22 changed files with 771 additions and 596 deletions
Download Patch File Download Diff File Expand all files Collapse all files

97
pkg/scheduler/eventhandlers.go
View File

@@ -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)
klog.V(3).InfoS("Add event for node", "node", klog.KObj(node))
sched.SchedulingQueue.MoveAllToActiveOrBackoffQueue(queue.NodeAdd, preCheckForNode(nodeInfo))
nodeInfo := sched.Cache.AddNode(logger, node)
logger.V(3).Info("Add event for node", "node", klog.KObj(node))
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))
if err := sched.Cache.RemoveNode(node); err != nil {
klog.ErrorS(err, "Scheduler cache RemoveNode failed")
logger.V(3).Info("Delete event for node", "node", klog.KObj(node))
if err := sched.Cache.RemoveNode(logger, node); err != nil {
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))
if err := sched.SchedulingQueue.Add(pod); err != nil {
logger.V(3).Info("Add event for unscheduled pod", "pod", klog.KObj(pod))
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 {
klog.ErrorS(err, "Scheduler cache AddPod failed", "pod", klog.KObj(pod))
if err := sched.Cache.AddPod(logger, pod); err != nil {
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 {
klog.ErrorS(err, "Scheduler cache UpdatePod failed", "pod", klog.KObj(oldPod))
if err := sched.Cache.UpdatePod(logger, oldPod, newPod); err != nil {
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))
if err := sched.Cache.RemovePod(pod); err != nil {
klog.ErrorS(err, "Scheduler cache RemovePod failed", "pod", klog.KObj(pod))
logger.V(3).Info("Delete event for scheduled pod", "pod", klog.KObj(pod))
if err := sched.Cache.RemovePod(logger, pod); err != nil {
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.

11
pkg/scheduler/eventhandlers_test.go
View File

@@ -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)

5
pkg/scheduler/extender_test.go
View File

@@ -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()

5
pkg/scheduler/framework/interface.go
View File

@@ -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
}

6
pkg/scheduler/framework/plugins/defaultpreemption/default_preemption_test.go
View File

@@ -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.

2
pkg/scheduler/framework/runtime/framework_test.go
View File

@@ -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})
}

148
pkg/scheduler/internal/cache/cache.go vendored
View File

@@ -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.
// "stop" is the channel that would close the background goroutine.
func New(ttl time.Duration, stop <-chan struct{}) Cache {
cache := newCache(ttl, cleanAssumedPeriod, stop)
cache.run()
// "ttl" is how long the assumed pod will get expired.
// "ctx" is the context that would close the background goroutine.
func New(ctx context.Context, ttl time.Duration) Cache {
logger := klog.FromContext(ctx)
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 {
return cache.finishBinding(pod, time.Now())
func (cache *cacheImpl) FinishBinding(logger klog.Logger, pod *v1.Pod) error {
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 {
if err := cache.removePod(oldPod); err != nil {
func (cache *cacheImpl) updatePod(logger klog.Logger, oldPod, newPod *v1.Pod) error {
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 {
klog.ErrorS(err, "Error occurred while updating pod")
if err = cache.updatePod(logger, currState.pod, pod); err != nil {
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 {
klog.ErrorS(err, "Error occurred while adding pod")
if err = cache.addPod(logger, pod, false); err != nil {
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))
klog.ErrorS(nil, "scheduler cache is corrupted and can badly affect scheduling decisions")
logger.Error(nil, "Pod updated on a different node than previously added to", "podKey", key, "pod", klog.KObj(oldPod))
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() {
go wait.Until(cache.cleanupExpiredAssumedPods, cache.period, cache.stop)
}
func (cache *cacheImpl) cleanupExpiredAssumedPods() {
cache.cleanupAssumedPods(time.Now())
func (cache *cacheImpl) run(logger klog.Logger) {
go wait.Until(func() {
cache.cleanupAssumedPods(logger, time.Now())
}, cache.period, cache.stop)
}
// 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))
if err := cache.removePod(ps.pod); err != nil {
klog.ErrorS(err, "ExpirePod failed", "podKey", key, "pod", klog.KObj(ps.pod))
logger.Info("Pod expired", "podKey", key, "pod", klog.KObj(ps.pod))
if err := cache.removePod(logger, ps.pod); err != nil {
logger.Error(err, "ExpirePod failed", "podKey", key, "pod", klog.KObj(ps.pod))
}
}
}

245
pkg/scheduler/internal/cache/cache_test.go vendored
View File

@@ -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 {
if err := cache.AssumePod(pod); err != nil {
func assumeAndFinishBinding(logger klog.Logger, cache *cacheImpl, pod *v1.Pod, assumedTime time.Time) error {
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)
if err := assumeAndFinishBinding(cache, tt.pod, now); err != nil {
cache := newCache(ctx, ttl, time.Second)
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 {
return cache.AssumePod(pod)
handler: func(logger klog.Logger, cache Cache, pod *v1.Pod) error {
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 {
return cache.AddPod(pod)
handler: func(logger klog.Logger, cache Cache, pod *v1.Pod) error {
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)
if err := cache.AddPod(tt.pod); err != nil {
logger, ctx := ktesting.NewTestContext(t)
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.AddNode(node)
cache := newCache(ctx, time.Second, time.Second)
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)
}

10
pkg/scheduler/internal/cache/debugger/comparer.go vendored
View File

@@ -38,9 +38,9 @@ type CacheComparer struct {
}
// Compare compares the nodes and pods of NodeLister with Cache.Snapshot.
func (c *CacheComparer) Compare() error {
klog.V(3).InfoS("Cache comparer started")
defer klog.V(3).InfoS("Cache comparer finished")
func (c *CacheComparer) Compare(logger klog.Logger) error {
logger.V(3).Info("Cache comparer started")
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

10
pkg/scheduler/internal/cache/debugger/debugger.go vendored
View File

@@ -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.Dumper.DumpAll()
d.Comparer.Compare(logger)
d.Dumper.DumpAll(logger)
}
}
}()

14
pkg/scheduler/internal/cache/debugger/dumper.go vendored
View File

@@ -36,30 +36,30 @@ type CacheDumper struct {
}
// DumpAll writes cached nodes and scheduling queue information to the scheduler logs.
func (d *CacheDumper) DumpAll() {
d.dumpNodes()
d.dumpSchedulingQueue()
func (d *CacheDumper) DumpAll(logger klog.Logger) {
d.dumpNodes(logger)
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.

23
pkg/scheduler/internal/cache/fake/fake_cache.go vendored
View File

@@ -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
}

21
pkg/scheduler/internal/cache/interface.go vendored
View File

@@ -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

22
pkg/scheduler/internal/cache/node_tree.go vendored
View File

@@ -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.addNode(new)
nt.removeNode(logger, old) // No error checking. We ignore whether the old node exists or not.
nt.addNode(logger, new)
}
// list returns the list of names of the node. NodeTree iterates over zones and in each zone iterates

29
pkg/scheduler/internal/cache/node_tree_test.go vendored
View File

@@ -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:

155
pkg/scheduler/internal/queue/scheduling_queue.go
View File

@@ -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)
AssignedPodAdded(pod *v1.Pod)
AssignedPodUpdated(pod *v1.Pod)
MoveAllToActiveOrBackoffQueue(logger klog.Logger, event framework.ClusterEvent, preCheck PreEnqueueCheck)
AssignedPodAdded(logger klog.Logger, 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() {
go wait.Until(p.flushBackoffQCompleted, 1.0*time.Second, p.stop)
go wait.Until(p.flushUnschedulablePodsLeftover, 30*time.Second, p.stop)
func (p *PriorityQueue) Run(logger klog.Logger) {
go wait.Until(func() {
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 {
klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pod), "event", BackoffComplete, "queue", activeQName)
if added, _ := p.addToActiveQ(logger, pInfo); added {
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)
klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", PodUpdate, "queue", activeQName)
p.addNominatedPodUnlocked(logger, pInfo.PodInfo, nil)
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 {
klog.V(5).InfoS("Pod moved to an internal scheduling queue", "pod", klog.KObj(pInfo.Pod), "event", event, "queue", activeQName)
if added, _ := p.addToActiveQ(logger, pInfo); added {
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
}
}

306
pkg/scheduler/internal/queue/scheduling_queue_test.go
View File

@@ -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.AddUnschedulableIfNotPresent(newQueuedPodInfoForLookup(highPriNominatedPodInfo.Pod), q.SchedulingCycle()) // Must not add anything.
q.AddUnschedulableIfNotPresent(newQueuedPodInfoForLookup(unschedulablePodInfo.Pod), q.SchedulingCycle())
q.Add(logger, highPriNominatedPodInfo.Pod)
q.AddUnschedulableIfNotPresent(logger, newQueuedPodInfoForLookup(highPriNominatedPodInfo.Pod), q.SchedulingCycle()) // Must not add anything.
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.Add(unschedulablePodInfo.Pod)
q.Update(logger, highPriorityPodInfo.Pod, highPriNominatedPodInfo.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.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(unschedulablePodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(highPriorityPodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
q.Add(logger, medPriorityPodInfo.Pod)
q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(unschedulablePodInfo.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(q.newQueuedPodInfo(highPriorityPodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(hpp1), q.SchedulingCycle())
q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(unschedulablePodInfo.Pod, "fooPlugin"), q.SchedulingCycle())
q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(highPriorityPodInfo.Pod, "fooPlugin"), 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(q.newQueuedPodInfo(affinityPod, "fakePlugin"), q.SchedulingCycle())
q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(unschedulablePodInfo.Pod, "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(unschedulablePodInfo.Pod)
q.Add(highPriorityPodInfo.Pod)
q.Add(logger, medPriorityPodInfo.Pod)
q.Add(logger, unschedulablePodInfo.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.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(unschedulablePodInfo.Pod), q.SchedulingCycle())
q.AddUnschedulableIfNotPresent(q.newQueuedPodInfo(highPriorityPodInfo.Pod), q.SchedulingCycle())
q.Add(logger, medPriorityPodInfo.Pod)
q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(unschedulablePodInfo.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}
ctx, cancel := context.WithCancel(context.Background())
logger, ctx := ktesting.NewTestContext(t)
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(highPod)
q.Add(logger, midPod)
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(q.newQueuedPodInfo(midPod, "fakePlugin"), q.SchedulingCycle())
q.AddUnschedulableIfNotPresent(logger, q.newQueuedPodInfo(highPod, "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) {
queue.Add(pInfo.Pod)
add = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
queue.Add(logger, pInfo.Pod)
}
addUnschedulablePodBackToUnschedulablePods = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
queue.AddUnschedulableIfNotPresent(pInfo, 0)
addUnschedulablePodBackToUnschedulablePods = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
queue.AddUnschedulableIfNotPresent(logger, pInfo, 0)
}
addUnschedulablePodBackToBackoffQ = func(queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
queue.AddUnschedulableIfNotPresent(pInfo, -1)
addUnschedulablePodBackToBackoffQ = func(logger klog.Logger, queue *PriorityQueue, pInfo *framework.QueuedPodInfo) {
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) {
queue.MoveAllToActiveOrBackoffQueue(UnschedulableTimeout, nil)
moveAllToActiveOrBackoffQ = func(logger klog.Logger, queue *PriorityQueue, _ *framework.QueuedPodInfo) {
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()

131
pkg/scheduler/schedule_one.go
View File

@@ -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 {
klog.ErrorS(forgetErr, "Scheduler cache ForgetPod failed")
if forgetErr := sched.Cache.ForgetPod(logger, assumedPod); forgetErr != nil {
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 {
klog.ErrorS(forgetErr, "Scheduler cache ForgetPod failed")
if forgetErr := sched.Cache.ForgetPod(logger, assumedPod); forgetErr != nil {
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 {
klog.ErrorS(forgetErr, "scheduler cache ForgetPod failed")
if forgetErr := sched.Cache.ForgetPod(logger, assumedPod); forgetErr != nil {
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(sched.nodeInfoSnapshot); err != nil {
if err := sched.Cache.UpdateSnapshot(klog.FromContext(ctx), 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)
if klogV.Enabled() {
loggerVTen := logger.V(10)
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() {
klogV.InfoS("Extender scored node for pod", "pod", klog.KObj(pod), "extender", extenders[extIndex].Name(), "node", nodename, "score", score)
if loggerVTen.Enabled() {
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 {
klog.ErrorS(err, "Scheduler cache AssumePod failed")
if err := sched.Cache.AssumePod(logger, assumed); err != nil {
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) {
if finErr := sched.Cache.FinishBinding(assumed); finErr != nil {
klog.ErrorS(finErr, "Scheduler cache FinishBinding failed")
func (sched *Scheduler) finishBinding(logger klog.Logger, fwk framework.Framework, assumed *v1.Pod, targetNode string, status *framework.Status) {
if finErr := sched.Cache.FinishBinding(logger, assumed); finErr != nil {
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 {
// Inject UnschedulablePlugins to PodInfo, which will be used later for moving Pods between queues efficiently.
logger.V(2).Info("Unable to schedule pod; no nodes are registered to the cluster; waiting", "pod", klog.KObj(pod))
} 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 {
klog.V(4).InfoS("Node is not found; failed to remove it from the cache", "node", node.Name)
if err := sched.Cache.RemoveNode(logger, &node); err != nil {
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 {
klog.ErrorS(err, "Error occurred")
if err := sched.SchedulingQueue.AddUnschedulableIfNotPresent(logger, podInfo, sched.SchedulingQueue.SchedulingCycle()); err != nil {
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.

75
pkg/scheduler/schedule_one_test.go
View File

@@ -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()),
&framework.NominatingInfo{NominatingMode: framework.ModeOverride, NominatedNodeName: "1"})
podinfo, err := framework.NewPodInfo(st.MakePod().UID("nominated").Priority(midPriority).Obj())
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.AddNode(&testNode)
scache := internalcache.New(ctx, 10*time.Minute)
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)

22
pkg/scheduler/scheduler.go
View File

@@ -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

26
pkg/scheduler/scheduler_test.go
View File

@@ -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()

4
test/integration/scheduler/queue_test.go
View File

@@ -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.