From 6c4f71b31cefa01c109f498c356b82d6511e8a7b Mon Sep 17 00:00:00 2001 From: Maciej Szulik Date: Wed, 18 Oct 2023 19:15:34 +0200 Subject: [PATCH 1/3] Fix spelling --- pkg/controller/cronjob/utils_test.go | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-) diff --git a/pkg/controller/cronjob/utils_test.go b/pkg/controller/cronjob/utils_test.go index e0012e986d5..f89d079fef4 100644 --- a/pkg/controller/cronjob/utils_test.go +++ b/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) } From db8b303156112e920a64df85666a3e04ae2bc7f6 Mon Sep 17 00:00:00 2001 From: Maciej Szulik Date: Wed, 18 Oct 2023 19:29:03 +0200 Subject: [PATCH 2/3] Modify mostRecentScheduleTime to return more detailed information about missed schedules Initially this method was returning a number of missed schedules, but that turned out to be not reliable for some complex schedules. For example, those which are being run only during week days. The second approach was to only return a boolean indicating the too many missed information. It turns out that we need to return all three values: none missed, few missed and many missed, to let consumers know what to do, but don't leak the wrong number out of mostRecentScheduleTime. --- pkg/controller/cronjob/utils.go | 59 +++++++++++++---- pkg/controller/cronjob/utils_test.go | 96 +++++++++++++++++++++++----- 2 files changed, 125 insertions(+), 30 deletions(-) diff --git a/pkg/controller/cronjob/utils.go b/pkg/controller/cronjob/utils.go index 1ca6dd819a2..b88504d1182 100644 --- a/pkg/controller/cronjob/utils.go +++ b/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 { - // no missed schedules since earliestTime - mostRecentTime = &earliestTime + 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)) } diff --git a/pkg/controller/cronjob/utils_test.go b/pkg/controller/cronjob/utils_test.go index f89d079fef4..1d61a38251b 100644 --- a/pkg/controller/cronjob/utils_test.go +++ b/pkg/controller/cronjob/utils_test.go @@ -364,7 +364,7 @@ func TestMostRecentScheduleTime(t *testing.T) { now time.Time expectedEarliestTime time.Time expectedRecentTime *time.Time - expectedTooManyMissed bool + expectedTooManyMissed missedSchedulesType wantErr bool }{ { @@ -405,9 +405,10 @@ func TestMostRecentScheduleTime(t *testing.T) { Schedule: "0 * * * *", }, }, - now: *deltaTimeAfterTopOfTheHour(301 * time.Minute), - expectedRecentTime: deltaTimeAfterTopOfTheHour(300 * time.Minute), - expectedEarliestTime: *deltaTimeAfterTopOfTheHour(10 * time.Second), + now: *deltaTimeAfterTopOfTheHour(301 * time.Minute), + expectedRecentTime: deltaTimeAfterTopOfTheHour(300 * time.Minute), + expectedEarliestTime: *deltaTimeAfterTopOfTheHour(10 * time.Second), + expectedTooManyMissed: fewMissed, }, { name: "complex schedule", @@ -422,9 +423,10 @@ func TestMostRecentScheduleTime(t *testing.T) { LastScheduleTime: &metav1HalfPastTheHour, }, }, - now: *deltaTimeAfterTopOfTheHour(24*time.Hour + 31*time.Minute), - expectedRecentTime: deltaTimeAfterTopOfTheHour(24*time.Hour + 30*time.Minute), - expectedEarliestTime: *deltaTimeAfterTopOfTheHour(30 * time.Minute), + 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", @@ -439,9 +441,10 @@ func TestMostRecentScheduleTime(t *testing.T) { LastScheduleTime: &metav1HalfPastTheHour, }, }, - now: *deltaTimeAfterTopOfTheHour(30*time.Hour + 30*time.Minute), - expectedRecentTime: nil, - expectedEarliestTime: *deltaTimeAfterTopOfTheHour(30 * time.Minute), + 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", @@ -456,9 +459,10 @@ func TestMostRecentScheduleTime(t *testing.T) { LastScheduleTime: &metav1HalfPastTheHour, }, }, - now: *deltaTimeAfterTopOfTheHour(96*time.Hour + 31*time.Minute), - expectedRecentTime: deltaTimeAfterTopOfTheHour(96*time.Hour + 30*time.Minute), - expectedEarliestTime: *deltaTimeAfterTopOfTheHour(30 * time.Minute), + 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", @@ -470,9 +474,10 @@ func TestMostRecentScheduleTime(t *testing.T) { Schedule: "30 6-16/4 * * 1-5", }, }, - now: *deltaTimeAfterTopOfTheHour(24*time.Hour + 31*time.Minute), - expectedRecentTime: deltaTimeAfterTopOfTheHour(24*time.Hour + 30*time.Minute), - expectedEarliestTime: *topOfTheHour(), + 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,63 @@ func TestMostRecentScheduleTime(t *testing.T) { } } +func TestNextScheduleTimeDuration(t *testing.T) { + metav1TopOfTheHour := metav1.NewTime(*topOfTheHour()) + metav1HalfPastTheHour := metav1.NewTime(*deltaTimeAfterTopOfTheHour(30 * time.Minute)) + + 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, + }, + } + 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 !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 { From bf2f640ea2c65ce556d92f048b686862b39a8f39 Mon Sep 17 00:00:00 2001 From: Maciej Szulik Date: Mon, 23 Oct 2023 16:45:48 +0200 Subject: [PATCH 3/3] Add more test cases ensuring nextScheduleTimeDuration is never < 0 --- pkg/controller/cronjob/utils_test.go | 33 ++++++++++++++++++++++++++++ 1 file changed, 33 insertions(+) diff --git a/pkg/controller/cronjob/utils_test.go b/pkg/controller/cronjob/utils_test.go index 1d61a38251b..d190b310ae0 100644 --- a/pkg/controller/cronjob/utils_test.go +++ b/pkg/controller/cronjob/utils_test.go @@ -619,6 +619,7 @@ 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 @@ -658,6 +659,35 @@ func TestNextScheduleTimeDuration(t *testing.T) { 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) { @@ -666,6 +696,9 @@ func TestNextScheduleTimeDuration(t *testing.T) { 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) }