diff --git a/pkg/scheduler/framework/types.go b/pkg/scheduler/framework/types.go index fda3ced88af36..e291fba50ce8c 100644 --- a/pkg/scheduler/framework/types.go +++ b/pkg/scheduler/framework/types.go @@ -106,7 +106,7 @@ type QueuedPodInfo struct { // back to the queue multiple times before it's successfully scheduled. // It shouldn't be updated once initialized. It's used to record the e2e scheduling // latency for a pod. - InitialAttemptTimestamp time.Time + InitialAttemptTimestamp *time.Time // If a Pod failed in a scheduling cycle, record the plugin names it failed by. UnschedulablePlugins sets.String // Whether the Pod is scheduling gated (by PreEnqueuePlugins) or not. diff --git a/pkg/scheduler/internal/queue/scheduling_queue.go b/pkg/scheduler/internal/queue/scheduling_queue.go index 9e699614098bd..e802ee294fd49 100644 --- a/pkg/scheduler/internal/queue/scheduling_queue.go +++ b/pkg/scheduler/internal/queue/scheduling_queue.go @@ -386,6 +386,10 @@ func (p *PriorityQueue) addToActiveQ(pInfo *framework.QueuedPodInfo) (bool, erro p.unschedulablePods.addOrUpdate(pInfo) return false, nil } + if pInfo.InitialAttemptTimestamp == nil { + now := p.clock.Now() + pInfo.InitialAttemptTimestamp = &now + } if err := p.activeQ.Add(pInfo); err != nil { klog.ErrorS(err, "Error adding pod to the active queue", "pod", klog.KObj(pInfo.Pod)) return false, err @@ -900,7 +904,7 @@ func (p *PriorityQueue) newQueuedPodInfo(pod *v1.Pod, plugins ...string) *framew return &framework.QueuedPodInfo{ PodInfo: podInfo, Timestamp: now, - InitialAttemptTimestamp: now, + InitialAttemptTimestamp: nil, UnschedulablePlugins: sets.NewString(plugins...), } } diff --git a/pkg/scheduler/internal/queue/scheduling_queue_test.go b/pkg/scheduler/internal/queue/scheduling_queue_test.go index 99a4188376a41..a897c6f3cefbd 100644 --- a/pkg/scheduler/internal/queue/scheduling_queue_test.go +++ b/pkg/scheduler/internal/queue/scheduling_queue_test.go @@ -1870,6 +1870,38 @@ func TestPerPodSchedulingMetrics(t *testing.T) { t.Fatalf("Failed to pop a pod %v", err) } checkPerPodSchedulingMetrics("Attempt twice with update", t, pInfo, 2, timestamp) + + // Case 4: A gated pod is created and scheduled after lifting gate. The queue operations are + // Add gated pod -> check unschedulablePods -> lift gate & update pod -> Pop. + c = testingclock.NewFakeClock(timestamp) + // Create a queue with PreEnqueuePlugin + m := map[string][]framework.PreEnqueuePlugin{"": {&preEnqueuePlugin{allowlists: []string{"foo"}}}} + queue = NewTestQueue(ctx, newDefaultQueueSort(), WithClock(c), WithPreEnqueuePluginMap(m), WithPluginMetricsSamplePercent(0)) + + // Create a pod without PreEnqueuePlugin label. + gatedPod := st.MakePod().Name("gated-test-pod").Namespace("test-ns").UID("test-uid").Obj() + err = queue.Add(gatedPod) + if err != nil { + t.Fatalf("Failed to add a pod %v", err) + } + // Check pod is added to the unschedulablePods queue. + if getUnschedulablePod(queue, gatedPod) != gatedPod { + t.Errorf("Pod %v was not found in the unschedulablePods.", gatedPod.Name) + } + // Override clock to get different InitialAttemptTimestamp + c.Step(1 * time.Minute) + + // Update pod with the required label to get it out of unschedulablePods queue. + updateGatedPod := gatedPod.DeepCopy() + updateGatedPod.Labels = map[string]string{"foo": ""} + queue.Update(gatedPod, updateGatedPod) + + pInfo, err = queue.Pop() + if err != nil { + t.Fatalf("Failed to pop a pod %v", err) + } + + checkPerPodSchedulingMetrics("Attempt once/gated", t, pInfo, 1, timestamp.Add(1*time.Minute)) } func TestIncomingPodsMetrics(t *testing.T) { @@ -1965,8 +1997,8 @@ func checkPerPodSchedulingMetrics(name string, t *testing.T, pInfo *framework.Qu if pInfo.Attempts != wantAttempts { t.Errorf("[%s] Pod schedule attempt unexpected, got %v, want %v", name, pInfo.Attempts, wantAttempts) } - if pInfo.InitialAttemptTimestamp != wantInitialAttemptTs { - t.Errorf("[%s] Pod initial schedule attempt timestamp unexpected, got %v, want %v", name, pInfo.InitialAttemptTimestamp, wantInitialAttemptTs) + if *pInfo.InitialAttemptTimestamp != wantInitialAttemptTs { + t.Errorf("[%s] Pod initial schedule attempt timestamp unexpected, got %v, want %v", name, *pInfo.InitialAttemptTimestamp, wantInitialAttemptTs) } } diff --git a/pkg/scheduler/schedule_one.go b/pkg/scheduler/schedule_one.go index 90e2d30e9c99b..8c88f88031016 100644 --- a/pkg/scheduler/schedule_one.go +++ b/pkg/scheduler/schedule_one.go @@ -252,8 +252,9 @@ func (sched *Scheduler) bindingCycle( klog.V(2).InfoS("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)) - + if assumedPodInfo.InitialAttemptTimestamp != nil { + metrics.PodSchedulingDuration.WithLabelValues(getAttemptsLabel(assumedPodInfo)).Observe(metrics.SinceInSeconds(*assumedPodInfo.InitialAttemptTimestamp)) + } // Run "postbind" plugins. fwk.RunPostBindPlugins(ctx, state, assumedPod, scheduleResult.SuggestedHost)