Merge pull request #121327 from soltysh/fix_nextScheduleTimeDuration

Fix next schedule time duration

pkg/controller/cronjob/utils.go

@@ -36,6 +36,27 @@ import (
 
 // Utilities for dealing with Jobs and CronJobs and time.
 
+type missedSchedulesType int
+
+const (
+	noneMissed missedSchedulesType = iota
+	fewMissed
+	manyMissed
+)
+
+func (e missedSchedulesType) String() string {
+	switch e {
+	case noneMissed:
+		return "none"
+	case fewMissed:
+		return "few"
+	case manyMissed:
+		return "many"
+	default:
+		return fmt.Sprintf("unknown(%d)", int(e))
+	}
+}
+
 // inActiveList checks if cronjob's .status.active has a job with the same UID.
 func inActiveList(cj *batchv1.CronJob, uid types.UID) bool {
 	for _, j := range cj.Status.Active {
@@ -75,11 +96,12 @@ func deleteFromActiveList(cj *batchv1.CronJob, uid types.UID) {
 // mostRecentScheduleTime returns:
 //   - the last schedule time or CronJob's creation time,
 //   - the most recent time a Job should be created or nil, if that's after now,
-//   - boolean indicating an excessive number of missed schedules,
+//   - value indicating either none missed schedules, a few missed or many missed
 //   - error in an edge case where the schedule specification is grammatically correct,
 //     but logically doesn't make sense (31st day for months with only 30 days, for example).
-func mostRecentScheduleTime(cj *batchv1.CronJob, now time.Time, schedule cron.Schedule, includeStartingDeadlineSeconds bool) (time.Time, *time.Time, bool, error) {
+func mostRecentScheduleTime(cj *batchv1.CronJob, now time.Time, schedule cron.Schedule, includeStartingDeadlineSeconds bool) (time.Time, *time.Time, missedSchedulesType, error) {
 	earliestTime := cj.ObjectMeta.CreationTimestamp.Time
+	missedSchedules := noneMissed
 	if cj.Status.LastScheduleTime != nil {
 		earliestTime = cj.Status.LastScheduleTime.Time
 	}
@@ -96,10 +118,10 @@ func mostRecentScheduleTime(cj *batchv1.CronJob, now time.Time, schedule cron.Sc
 	t2 := schedule.Next(t1)
 
 	if now.Before(t1) {
-		return earliestTime, nil, false, nil
+		return earliestTime, nil, missedSchedules, nil
 	}
 	if now.Before(t2) {
-		return earliestTime, &t1, false, nil
+		return earliestTime, &t1, missedSchedules, nil
 	}
 
 	// It is possible for cron.ParseStandard("59 23 31 2 *") to return an invalid schedule
@@ -107,7 +129,7 @@ func mostRecentScheduleTime(cj *batchv1.CronJob, now time.Time, schedule cron.Sc
 	// In this case the timeBetweenTwoSchedules will be 0, and we error out the invalid schedule
 	timeBetweenTwoSchedules := int64(t2.Sub(t1).Round(time.Second).Seconds())
 	if timeBetweenTwoSchedules < 1 {
-		return earliestTime, nil, false, fmt.Errorf("time difference between two schedules is less than 1 second")
+		return earliestTime, nil, missedSchedules, fmt.Errorf("time difference between two schedules is less than 1 second")
 	}
 	// this logic used for calculating number of missed schedules does a rough
 	// approximation, by calculating a diff between two schedules (t1 and t2),
@@ -146,12 +168,18 @@ func mostRecentScheduleTime(cj *batchv1.CronJob, now time.Time, schedule cron.Sc
 	//
 	// I've somewhat arbitrarily picked 100, as more than 80,
 	// but less than "lots".
-	tooManyMissed := numberOfMissedSchedules > 100
+	switch {
+	case numberOfMissedSchedules > 100:
+		missedSchedules = manyMissed
+	// inform about few missed, still
+	case numberOfMissedSchedules > 0:
+		missedSchedules = fewMissed
+	}
 
 	if mostRecentTime.IsZero() {
-		return earliestTime, nil, tooManyMissed, nil
+		return earliestTime, nil, missedSchedules, nil
 	}
-	return earliestTime, &mostRecentTime, tooManyMissed, nil
+	return earliestTime, &mostRecentTime, missedSchedules, nil
 }
 
 // nextScheduleTimeDuration returns the time duration to requeue based on
@@ -160,13 +188,18 @@ func mostRecentScheduleTime(cj *batchv1.CronJob, now time.Time, schedule cron.Sc
 // realistic cases should be around 100s, the job will still be executed without missing
 // the schedule.
 func nextScheduleTimeDuration(cj *batchv1.CronJob, now time.Time, schedule cron.Schedule) *time.Duration {
-	earliestTime, mostRecentTime, _, err := mostRecentScheduleTime(cj, now, schedule, false)
+	earliestTime, mostRecentTime, missedSchedules, err := mostRecentScheduleTime(cj, now, schedule, false)
 	if err != nil {
 		// we still have to requeue at some point, so aim for the next scheduling slot from now
 		mostRecentTime = &now
 	} else if mostRecentTime == nil {
+		if missedSchedules == noneMissed {
 			// no missed schedules since earliestTime
 			mostRecentTime = &earliestTime
+		} else {
+			// if there are missed schedules since earliestTime, always use now
+			mostRecentTime = &now
+		}
 	}
 
 	t := schedule.Next(*mostRecentTime).Add(nextScheduleDelta).Sub(now)
@@ -177,13 +210,13 @@ func nextScheduleTimeDuration(cj *batchv1.CronJob, now time.Time, schedule cron.
 // and before now, or nil if no unmet schedule times, and an error.
 // If there are too many (>100) unstarted times, it will also record a warning.
 func nextScheduleTime(logger klog.Logger, cj *batchv1.CronJob, now time.Time, schedule cron.Schedule, recorder record.EventRecorder) (*time.Time, error) {
-	_, mostRecentTime, tooManyMissed, err := mostRecentScheduleTime(cj, now, schedule, true)
+	_, mostRecentTime, missedSchedules, err := mostRecentScheduleTime(cj, now, schedule, true)
 
 	if mostRecentTime == nil || mostRecentTime.After(now) {
 		return nil, err
 	}
 
-	if tooManyMissed {
+	if missedSchedules == manyMissed {
 		recorder.Eventf(cj, corev1.EventTypeWarning, "TooManyMissedTimes", "too many missed start times. Set or decrease .spec.startingDeadlineSeconds or check clock skew")
 		logger.Info("too many missed times", "cronjob", klog.KObj(cj))
 	}

pkg/controller/cronjob/utils_test.go

@@ -157,7 +157,7 @@ func TestNextScheduleTime(t *testing.T) {
 	// schedule is hourly on the hour
 	schedule := "0 * * * ?"
 
-	PraseSchedule := func(schedule string) cron.Schedule {
+	ParseSchedule := func(schedule string) cron.Schedule {
 		sched, err := cron.ParseStandard(schedule)
 		if err != nil {
 			t.Errorf("Error parsing schedule: %#v", err)
@@ -189,7 +189,7 @@ func TestNextScheduleTime(t *testing.T) {
 		cj.ObjectMeta.CreationTimestamp = metav1.Time{Time: T1.Add(-10 * time.Minute)}
 		// Current time is more than creation time, but less than T1.
 		now := T1.Add(-7 * time.Minute)
-		schedule, _ := nextScheduleTime(logger, &cj, now, PraseSchedule(cj.Spec.Schedule), recorder)
+		schedule, _ := nextScheduleTime(logger, &cj, now, ParseSchedule(cj.Spec.Schedule), recorder)
 		if schedule != nil {
 			t.Errorf("expected no start time, got:  %v", schedule)
 		}
@@ -200,7 +200,7 @@ func TestNextScheduleTime(t *testing.T) {
 		cj.ObjectMeta.CreationTimestamp = metav1.Time{Time: T1.Add(-10 * time.Minute)}
 		// Current time is after T1
 		now := T1.Add(2 * time.Second)
-		schedule, _ := nextScheduleTime(logger, &cj, now, PraseSchedule(cj.Spec.Schedule), recorder)
+		schedule, _ := nextScheduleTime(logger, &cj, now, ParseSchedule(cj.Spec.Schedule), recorder)
 		if schedule == nil {
 			t.Errorf("expected 1 start time, got nil")
 		} else if !schedule.Equal(T1) {
@@ -215,7 +215,7 @@ func TestNextScheduleTime(t *testing.T) {
 		cj.Status.LastScheduleTime = &metav1.Time{Time: T1}
 		// Current time is after T1
 		now := T1.Add(2 * time.Minute)
-		schedule, _ := nextScheduleTime(logger, &cj, now, PraseSchedule(cj.Spec.Schedule), recorder)
+		schedule, _ := nextScheduleTime(logger, &cj, now, ParseSchedule(cj.Spec.Schedule), recorder)
 		if schedule != nil {
 			t.Errorf("expected 0 start times, got: %v", schedule)
 		}
@@ -228,7 +228,7 @@ func TestNextScheduleTime(t *testing.T) {
 		cj.Status.LastScheduleTime = &metav1.Time{Time: T1}
 		// Current time is after T1 and after T2
 		now := T2.Add(5 * time.Minute)
-		schedule, _ := nextScheduleTime(logger, &cj, now, PraseSchedule(cj.Spec.Schedule), recorder)
+		schedule, _ := nextScheduleTime(logger, &cj, now, ParseSchedule(cj.Spec.Schedule), recorder)
 		if schedule == nil {
 			t.Errorf("expected 1 start times, got nil")
 		} else if !schedule.Equal(T2) {
@@ -241,7 +241,7 @@ func TestNextScheduleTime(t *testing.T) {
 		cj.Status.LastScheduleTime = &metav1.Time{Time: T1.Add(-1 * time.Hour)}
 		// Current time is after T1 and after T2
 		now := T2.Add(5 * time.Minute)
-		schedule, _ := nextScheduleTime(logger, &cj, now, PraseSchedule(cj.Spec.Schedule), recorder)
+		schedule, _ := nextScheduleTime(logger, &cj, now, ParseSchedule(cj.Spec.Schedule), recorder)
 		if schedule == nil {
 			t.Errorf("expected 1 start times, got nil")
 		} else if !schedule.Equal(T2) {
@@ -253,7 +253,7 @@ func TestNextScheduleTime(t *testing.T) {
 		cj.ObjectMeta.CreationTimestamp = metav1.Time{Time: T1.Add(-2 * time.Hour)}
 		cj.Status.LastScheduleTime = &metav1.Time{Time: T1.Add(-1 * time.Hour)}
 		now := T2.Add(10 * 24 * time.Hour)
-		schedule, _ := nextScheduleTime(logger, &cj, now, PraseSchedule(cj.Spec.Schedule), recorder)
+		schedule, _ := nextScheduleTime(logger, &cj, now, ParseSchedule(cj.Spec.Schedule), recorder)
 		if schedule == nil {
 			t.Errorf("expected more than 0 missed times")
 		}
@@ -266,7 +266,7 @@ func TestNextScheduleTime(t *testing.T) {
 		// Deadline is short
 		deadline := int64(2 * 60 * 60)
 		cj.Spec.StartingDeadlineSeconds = &deadline
-		schedule, _ := nextScheduleTime(logger, &cj, now, PraseSchedule(cj.Spec.Schedule), recorder)
+		schedule, _ := nextScheduleTime(logger, &cj, now, ParseSchedule(cj.Spec.Schedule), recorder)
 		if schedule == nil {
 			t.Errorf("expected more than 0 missed times")
 		}
@@ -277,7 +277,7 @@ func TestNextScheduleTime(t *testing.T) {
 		cj.Status.LastScheduleTime = nil
 		now := *deltaTimeAfterTopOfTheHour(1 * time.Hour)
 		// rouge schedule
-		schedule, err := nextScheduleTime(logger, &cj, now, PraseSchedule("59 23 31 2 *"), recorder)
+		schedule, err := nextScheduleTime(logger, &cj, now, ParseSchedule("59 23 31 2 *"), recorder)
 		if schedule != nil {
 			t.Errorf("expected no start time, got:  %v", schedule)
 		}
@@ -364,7 +364,7 @@ func TestMostRecentScheduleTime(t *testing.T) {
 		now                   time.Time
 		expectedEarliestTime  time.Time
 		expectedRecentTime    *time.Time
-		expectedTooManyMissed bool
+		expectedTooManyMissed missedSchedulesType
 		wantErr               bool
 	}{
 		{
@@ -408,6 +408,7 @@ func TestMostRecentScheduleTime(t *testing.T) {
 			now:                   *deltaTimeAfterTopOfTheHour(301 * time.Minute),
 			expectedRecentTime:    deltaTimeAfterTopOfTheHour(300 * time.Minute),
 			expectedEarliestTime:  *deltaTimeAfterTopOfTheHour(10 * time.Second),
+			expectedTooManyMissed: fewMissed,
 		},
 		{
 			name: "complex schedule",
@@ -425,6 +426,7 @@ func TestMostRecentScheduleTime(t *testing.T) {
 			now:                   *deltaTimeAfterTopOfTheHour(24*time.Hour + 31*time.Minute),
 			expectedRecentTime:    deltaTimeAfterTopOfTheHour(24*time.Hour + 30*time.Minute),
 			expectedEarliestTime:  *deltaTimeAfterTopOfTheHour(30 * time.Minute),
+			expectedTooManyMissed: fewMissed,
 		},
 		{
 			name: "another complex schedule",
@@ -442,6 +444,7 @@ func TestMostRecentScheduleTime(t *testing.T) {
 			now:                   *deltaTimeAfterTopOfTheHour(30*time.Hour + 30*time.Minute),
 			expectedRecentTime:    nil,
 			expectedEarliestTime:  *deltaTimeAfterTopOfTheHour(30 * time.Minute),
+			expectedTooManyMissed: fewMissed,
 		},
 		{
 			name: "complex schedule with longer diff between executions",
@@ -459,6 +462,7 @@ func TestMostRecentScheduleTime(t *testing.T) {
 			now:                   *deltaTimeAfterTopOfTheHour(96*time.Hour + 31*time.Minute),
 			expectedRecentTime:    deltaTimeAfterTopOfTheHour(96*time.Hour + 30*time.Minute),
 			expectedEarliestTime:  *deltaTimeAfterTopOfTheHour(30 * time.Minute),
+			expectedTooManyMissed: fewMissed,
 		},
 		{
 			name: "complex schedule with shorter diff between executions",
@@ -473,6 +477,7 @@ func TestMostRecentScheduleTime(t *testing.T) {
 			now:                   *deltaTimeAfterTopOfTheHour(24*time.Hour + 31*time.Minute),
 			expectedRecentTime:    deltaTimeAfterTopOfTheHour(24*time.Hour + 30*time.Minute),
 			expectedEarliestTime:  *topOfTheHour(),
+			expectedTooManyMissed: fewMissed,
 		},
 		{
 			name: "@every schedule",
@@ -491,7 +496,7 @@ func TestMostRecentScheduleTime(t *testing.T) {
 			now:                   *deltaTimeAfterTopOfTheHour(7 * 24 * time.Hour),
 			expectedRecentTime:    deltaTimeAfterTopOfTheHour((6 * 24 * time.Hour) + 23*time.Hour + 1*time.Minute),
 			expectedEarliestTime:  *deltaTimeAfterTopOfTheHour(1 * time.Minute),
-			expectedTooManyMissed: true,
+			expectedTooManyMissed: manyMissed,
 		},
 		{
 			name: "rogue cronjob",
@@ -611,6 +616,96 @@ func TestMostRecentScheduleTime(t *testing.T) {
 	}
 }
 
+func TestNextScheduleTimeDuration(t *testing.T) {
+	metav1TopOfTheHour := metav1.NewTime(*topOfTheHour())
+	metav1HalfPastTheHour := metav1.NewTime(*deltaTimeAfterTopOfTheHour(30 * time.Minute))
+	metav1TwoHoursLater := metav1.NewTime(*deltaTimeAfterTopOfTheHour(2 * time.Hour))
+
+	tests := []struct {
+		name             string
+		cj               *batchv1.CronJob
+		now              time.Time
+		expectedDuration time.Duration
+	}{
+		{
+			name: "complex schedule skipping weekend",
+			cj: &batchv1.CronJob{
+				ObjectMeta: metav1.ObjectMeta{
+					CreationTimestamp: metav1TopOfTheHour,
+				},
+				Spec: batchv1.CronJobSpec{
+					Schedule: "30 6-16/4 * * 1-5",
+				},
+				Status: batchv1.CronJobStatus{
+					LastScheduleTime: &metav1HalfPastTheHour,
+				},
+			},
+			now:              *deltaTimeAfterTopOfTheHour(24*time.Hour + 31*time.Minute),
+			expectedDuration: 3*time.Hour + 59*time.Minute + nextScheduleDelta,
+		},
+		{
+			name: "another complex schedule skipping weekend",
+			cj: &batchv1.CronJob{
+				ObjectMeta: metav1.ObjectMeta{
+					CreationTimestamp: metav1TopOfTheHour,
+				},
+				Spec: batchv1.CronJobSpec{
+					Schedule: "30 10,11,12 * * 1-5",
+				},
+				Status: batchv1.CronJobStatus{
+					LastScheduleTime: &metav1HalfPastTheHour,
+				},
+			},
+			now:              *deltaTimeAfterTopOfTheHour(30*time.Hour + 30*time.Minute),
+			expectedDuration: 66*time.Hour + nextScheduleDelta,
+		},
+		{
+			name: "once a week cronjob, missed two runs",
+			cj: &batchv1.CronJob{
+				ObjectMeta: metav1.ObjectMeta{
+					CreationTimestamp: metav1TopOfTheHour,
+				},
+				Spec: batchv1.CronJobSpec{
+					Schedule: "0 12 * * 4",
+				},
+				Status: batchv1.CronJobStatus{
+					LastScheduleTime: &metav1TwoHoursLater,
+				},
+			},
+			now:              *deltaTimeAfterTopOfTheHour(19*24*time.Hour + 1*time.Hour + 30*time.Minute),
+			expectedDuration: 48*time.Hour + 30*time.Minute + nextScheduleDelta,
+		},
+		{
+			name: "no previous run of a cronjob",
+			cj: &batchv1.CronJob{
+				ObjectMeta: metav1.ObjectMeta{
+					CreationTimestamp: metav1TopOfTheHour,
+				},
+				Spec: batchv1.CronJobSpec{
+					Schedule: "0 12 * * 5",
+				},
+			},
+			now:              *deltaTimeAfterTopOfTheHour(6 * time.Hour),
+			expectedDuration: 20*time.Hour + nextScheduleDelta,
+		},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			sched, err := cron.ParseStandard(tt.cj.Spec.Schedule)
+			if err != nil {
+				t.Errorf("error setting up the test, %s", err)
+			}
+			gotScheduleTimeDuration := nextScheduleTimeDuration(tt.cj, tt.now, sched)
+			if *gotScheduleTimeDuration < 0 {
+				t.Errorf("scheduleTimeDuration should never be less than 0, got %s", gotScheduleTimeDuration)
+			}
+			if !reflect.DeepEqual(gotScheduleTimeDuration, &tt.expectedDuration) {
+				t.Errorf("scheduleTimeDuration - got %s, want %s", gotScheduleTimeDuration, tt.expectedDuration)
+			}
+		})
+	}
+}
+
 func topOfTheHour() *time.Time {
 	T1, err := time.Parse(time.RFC3339, "2016-05-19T10:00:00Z")
 	if err != nil {