zotregistry.dev/zot@v1.4.4-0.20240314164342-eec277e14d20/pkg/scheduler/scheduler_test.go (about) 1 package scheduler_test 2 3 import ( 4 "context" 5 "errors" 6 "fmt" 7 "os" 8 "runtime" 9 "strings" 10 "testing" 11 "time" 12 13 . "github.com/smartystreets/goconvey/convey" 14 15 "zotregistry.dev/zot/pkg/api/config" 16 "zotregistry.dev/zot/pkg/extensions/monitoring" 17 "zotregistry.dev/zot/pkg/log" 18 "zotregistry.dev/zot/pkg/scheduler" 19 ) 20 21 type task struct { 22 log log.Logger 23 msg string 24 err bool 25 delay time.Duration 26 } 27 28 var errInternal = errors.New("task: internal error") 29 30 func (t *task) DoWork(ctx context.Context) error { 31 if t.err { 32 return errInternal 33 } 34 35 for idx := 0; idx < 5; idx++ { 36 if ctx.Err() != nil { 37 return ctx.Err() 38 } 39 40 time.Sleep(t.delay) 41 } 42 43 t.log.Info().Msg(t.msg) 44 45 return nil 46 } 47 48 func (t *task) String() string { 49 return t.Name() 50 } 51 52 func (t *task) Name() string { 53 return "TestTask" 54 } 55 56 type generator struct { 57 log log.Logger 58 priority string 59 done bool 60 index int 61 step int 62 limit int 63 taskDelay time.Duration 64 } 65 66 func (g *generator) Name() string { 67 return "TestGenerator" 68 } 69 70 func (g *generator) Next() (scheduler.Task, error) { 71 if g.step > g.limit { 72 g.done = true 73 } 74 g.step++ 75 g.index++ 76 77 if g.step%11 == 0 { 78 return nil, nil 79 } 80 81 if g.step%13 == 0 { 82 return nil, errInternal 83 } 84 85 return &task{ 86 log: g.log, 87 msg: fmt.Sprintf("executing %s task; index: %d", g.priority, g.index), 88 err: false, 89 delay: g.taskDelay, 90 }, nil 91 } 92 93 func (g *generator) IsDone() bool { 94 return g.done 95 } 96 97 func (g *generator) IsReady() bool { 98 return true 99 } 100 101 func (g *generator) Reset() { 102 g.done = false 103 g.step = 0 104 } 105 106 type shortGenerator struct { 107 log log.Logger 108 priority string 109 done bool 110 index int 111 step int 112 } 113 114 func (g *shortGenerator) Name() string { 115 return "ShortTestGenerator" 116 } 117 118 func (g *shortGenerator) Next() (scheduler.Task, error) { 119 g.done = true 120 121 return &task{log: g.log, msg: fmt.Sprintf("executing %s task; index: %d", g.priority, g.index), err: false}, nil 122 } 123 124 func (g *shortGenerator) IsDone() bool { 125 return g.done 126 } 127 128 func (g *shortGenerator) IsReady() bool { 129 return true 130 } 131 132 func (g *shortGenerator) Reset() { 133 g.done = true 134 g.step = 0 135 } 136 137 func TestScheduler(t *testing.T) { 138 Convey("Test active to waiting periodic generator", t, func() { 139 logFile, err := os.CreateTemp("", "zot-log*.txt") 140 So(err, ShouldBeNil) 141 142 defer os.Remove(logFile.Name()) // clean up 143 144 logger := log.NewLogger("debug", logFile.Name()) 145 metrics := monitoring.NewMetricsServer(true, logger) 146 sch := scheduler.NewScheduler(config.New(), metrics, logger) 147 148 genH := &shortGenerator{log: logger, priority: "high priority"} 149 // interval has to be higher than throttle value to simulate 150 sch.SubmitGenerator(genH, 1*time.Second, scheduler.HighPriority) 151 152 sch.RunScheduler() 153 time.Sleep(2 * time.Second) 154 sch.Shutdown() 155 156 data, err := os.ReadFile(logFile.Name()) 157 So(err, ShouldBeNil) 158 So(string(data), ShouldContainSubstring, "waiting generator is ready, pushing to ready generators") 159 }) 160 161 Convey("Test order of generators in queue", t, func() { 162 logFile, err := os.CreateTemp("", "zot-log*.txt") 163 So(err, ShouldBeNil) 164 165 defer os.Remove(logFile.Name()) // clean up 166 167 logger := log.NewLogger("debug", logFile.Name()) 168 cfg := config.New() 169 cfg.Scheduler = &config.SchedulerConfig{NumWorkers: 3} 170 metrics := monitoring.NewMetricsServer(true, logger) 171 sch := scheduler.NewScheduler(cfg, metrics, logger) 172 sch.RateLimit = 5 * time.Second 173 174 genL := &generator{log: logger, priority: "low priority", limit: 100, taskDelay: 100 * time.Millisecond} 175 sch.SubmitGenerator(genL, time.Duration(0), scheduler.LowPriority) 176 177 genM := &generator{log: logger, priority: "medium priority", limit: 100, taskDelay: 100 * time.Millisecond} 178 sch.SubmitGenerator(genM, time.Duration(0), scheduler.MediumPriority) 179 180 genH := &generator{log: logger, priority: "high priority", limit: 100, taskDelay: 100 * time.Millisecond} 181 sch.SubmitGenerator(genH, time.Duration(0), scheduler.HighPriority) 182 183 sch.RunScheduler() 184 time.Sleep(4 * time.Second) 185 sch.Shutdown() 186 187 data, err := os.ReadFile(logFile.Name()) 188 So(err, ShouldBeNil) 189 190 So(string(data), ShouldContainSubstring, "executing high priority task; index: 1") 191 So(string(data), ShouldContainSubstring, "executing high priority task; index: 2") 192 So(string(data), ShouldNotContainSubstring, "executing medium priority task; index: 1") 193 So(string(data), ShouldNotContainSubstring, "failed to execute task") 194 }) 195 196 Convey("Test reordering of generators in queue", t, func() { 197 logFile, err := os.CreateTemp("", "zot-log*.txt") 198 So(err, ShouldBeNil) 199 200 defer os.Remove(logFile.Name()) // clean up 201 202 logger := log.NewLogger("debug", logFile.Name()) 203 cfg := config.New() 204 cfg.Scheduler = &config.SchedulerConfig{NumWorkers: 3} 205 metrics := monitoring.NewMetricsServer(true, logger) 206 sch := scheduler.NewScheduler(cfg, metrics, logger) 207 sch.RateLimit = 1 * time.Nanosecond 208 209 // Testing repordering of generators using the same medium priority, as well as reordering with 210 // a low priority generator 211 212 genL := &generator{log: logger, priority: "low priority", limit: 110, taskDelay: time.Nanosecond} 213 sch.SubmitGenerator(genL, time.Duration(0), scheduler.LowPriority) 214 215 genM := &generator{log: logger, priority: "medium 1 priority", limit: 110, taskDelay: time.Nanosecond} 216 sch.SubmitGenerator(genM, time.Duration(0), scheduler.MediumPriority) 217 218 genH := &generator{log: logger, priority: "medium 2 priority", limit: 110, taskDelay: time.Nanosecond} 219 sch.SubmitGenerator(genH, time.Duration(0), scheduler.MediumPriority) 220 221 sch.RunScheduler() 222 time.Sleep(1 * time.Second) 223 sch.Shutdown() 224 225 data, err := os.ReadFile(logFile.Name()) 226 So(err, ShouldBeNil) 227 228 // Check all tasks show up in the logs 229 for i := 1; i < 110; i++ { 230 if i%11 == 0 || i%13 == 0 { 231 continue 232 } 233 234 So(string(data), ShouldContainSubstring, fmt.Sprintf("executing medium 1 priority task; index: %d", i)) 235 So(string(data), ShouldContainSubstring, fmt.Sprintf("executing medium 2 priority task; index: %d", i)) 236 So(string(data), ShouldContainSubstring, fmt.Sprintf("executing low priority task; index: %d", i)) 237 } 238 239 taskCounter := 0 240 priorityFlippedCounter := 0 241 samePriorityFlippedCounter := 0 242 lastPriority := "medium" 243 lastMediumGenerator := "1" 244 245 for _, line := range strings.Split(strings.TrimSuffix(string(data), "\n"), "\n") { 246 if !strings.Contains(line, "priority task; index: ") { 247 continue 248 } 249 250 taskCounter++ 251 252 // low priority tasks start executing later 253 // medium priority generators are prioritized until the rank 100/9 (8 generated tasks) 254 // starting with 100/10, a low priority generator could potentially be prioritized instead 255 // there will be at least 8 * 2 medium priority tasks executed before low priority tasks are pushed 256 if taskCounter < 17 { 257 So(line, ShouldContainSubstring, "executing medium") 258 } 259 260 // medium priority 2*110 medium priority tasks should have been generated, 261 // medium priority generators should be done 262 // add around 10 low priority tasks to the counter 263 // and an additional margin of 5 to make sure the test is stable 264 if taskCounter > 225 { 265 So(line, ShouldContainSubstring, "executing low priority") 266 } 267 268 if strings.Contains(line, "executing medium") { 269 if !strings.Contains(line, fmt.Sprintf("executing medium %s", lastMediumGenerator)) { 270 samePriorityFlippedCounter++ 271 if lastMediumGenerator == "1" { 272 lastMediumGenerator = "2" 273 } else { 274 lastMediumGenerator = "1" 275 } 276 } 277 } 278 279 if !strings.Contains(line, fmt.Sprintf("executing %s", lastPriority)) { 280 priorityFlippedCounter++ 281 if lastPriority == "low" { 282 lastPriority = "medium" 283 } else { 284 lastPriority = "low" 285 } 286 } 287 } 288 289 // fairness: make sure none of the medium priority generators is favored by the algorithm 290 So(samePriorityFlippedCounter, ShouldBeGreaterThanOrEqualTo, 60) 291 t.Logf("Switched between medium priority generators %d times", samePriorityFlippedCounter) 292 // fairness: make sure the algorithm alternates between generator priorities 293 So(priorityFlippedCounter, ShouldBeGreaterThanOrEqualTo, 10) 294 t.Logf("Switched between generator priorities %d times", priorityFlippedCounter) 295 }) 296 297 Convey("Test task returning an error", t, func() { 298 logFile, err := os.CreateTemp("", "zot-log*.txt") 299 So(err, ShouldBeNil) 300 301 defer os.Remove(logFile.Name()) // clean up 302 303 logger := log.NewLogger("debug", logFile.Name()) 304 metrics := monitoring.NewMetricsServer(true, logger) 305 sch := scheduler.NewScheduler(config.New(), metrics, logger) 306 307 t := &task{log: logger, msg: "", err: true} 308 sch.SubmitTask(t, scheduler.MediumPriority) 309 310 sch.RunScheduler() 311 time.Sleep(500 * time.Millisecond) 312 sch.Shutdown() 313 314 data, err := os.ReadFile(logFile.Name()) 315 So(err, ShouldBeNil) 316 So(string(data), ShouldContainSubstring, "adding a new task") 317 So(string(data), ShouldContainSubstring, "failed to execute task") 318 }) 319 320 Convey("Test resubmit generator", t, func() { 321 logFile, err := os.CreateTemp("", "zot-log*.txt") 322 So(err, ShouldBeNil) 323 324 defer os.Remove(logFile.Name()) // clean up 325 326 logger := log.NewLogger("debug", logFile.Name()) 327 metrics := monitoring.NewMetricsServer(true, logger) 328 sch := scheduler.NewScheduler(config.New(), metrics, logger) 329 330 genL := &generator{log: logger, priority: "low priority", limit: 100, taskDelay: 100 * time.Millisecond} 331 sch.SubmitGenerator(genL, 20*time.Millisecond, scheduler.LowPriority) 332 333 sch.RunScheduler() 334 time.Sleep(1 * time.Second) 335 sch.Shutdown() 336 337 data, err := os.ReadFile(logFile.Name()) 338 So(err, ShouldBeNil) 339 So(string(data), ShouldContainSubstring, "executing low priority task; index: 1") 340 So(string(data), ShouldContainSubstring, "executing low priority task; index: 2") 341 }) 342 343 Convey("Try to add a task with wrong priority", t, func() { 344 logFile, err := os.CreateTemp("", "zot-log*.txt") 345 So(err, ShouldBeNil) 346 347 defer os.Remove(logFile.Name()) // clean up 348 349 logger := log.NewLogger("debug", logFile.Name()) 350 metrics := monitoring.NewMetricsServer(true, logger) 351 sch := scheduler.NewScheduler(config.New(), metrics, logger) 352 353 t := &task{log: logger, msg: "", err: false} 354 sch.SubmitTask(t, -1) 355 356 data, err := os.ReadFile(logFile.Name()) 357 So(err, ShouldBeNil) 358 So(string(data), ShouldNotContainSubstring, "adding a new task") 359 }) 360 361 Convey("Test adding a new task when context is done", t, func() { 362 logFile, err := os.CreateTemp("", "zot-log*.txt") 363 So(err, ShouldBeNil) 364 365 defer os.Remove(logFile.Name()) // clean up 366 367 logger := log.NewLogger("debug", logFile.Name()) 368 metrics := monitoring.NewMetricsServer(true, logger) 369 sch := scheduler.NewScheduler(config.New(), metrics, logger) 370 371 sch.RunScheduler() 372 sch.Shutdown() 373 time.Sleep(500 * time.Millisecond) 374 375 t := &task{log: logger, msg: "", err: false} 376 sch.SubmitTask(t, scheduler.LowPriority) 377 378 data, err := os.ReadFile(logFile.Name()) 379 So(err, ShouldBeNil) 380 So(string(data), ShouldNotContainSubstring, "adding a new task") 381 }) 382 383 Convey("Test stopping scheduler by calling Shutdown()", t, func() { 384 logFile, err := os.CreateTemp("", "zot-log*.txt") 385 So(err, ShouldBeNil) 386 387 defer os.Remove(logFile.Name()) // clean up 388 389 logger := log.NewLogger("debug", logFile.Name()) 390 metrics := monitoring.NewMetricsServer(true, logger) 391 sch := scheduler.NewScheduler(config.New(), metrics, logger) 392 393 genL := &generator{log: logger, priority: "medium priority", limit: 100, taskDelay: 100 * time.Millisecond} 394 sch.SubmitGenerator(genL, 20*time.Millisecond, scheduler.MediumPriority) 395 396 sch.RunScheduler() 397 time.Sleep(1 * time.Second) 398 sch.Shutdown() 399 400 data, err := os.ReadFile(logFile.Name()) 401 So(err, ShouldBeNil) 402 So(string(data), ShouldContainSubstring, "executing medium priority task; index: 1") 403 So(string(data), ShouldContainSubstring, "executing medium priority task; index: 2") 404 So(string(data), ShouldContainSubstring, "received stop signal, gracefully shutting down...") 405 }) 406 407 Convey("Test scheduler Priority.String() method", t, func() { 408 var p scheduler.Priority //nolint: varnamelen 409 // test invalid priority 410 p = 6238734 411 So(p.String(), ShouldEqual, "invalid") 412 p = scheduler.LowPriority 413 So(p.String(), ShouldEqual, "low") 414 p = scheduler.MediumPriority 415 So(p.String(), ShouldEqual, "medium") 416 p = scheduler.HighPriority 417 So(p.String(), ShouldEqual, "high") 418 }) 419 420 Convey("Test scheduler State.String() method", t, func() { 421 var s scheduler.State //nolint: varnamelen 422 // test invalid state 423 s = -67 424 So(s.String(), ShouldEqual, "invalid") 425 s = scheduler.Ready 426 So(s.String(), ShouldEqual, "ready") 427 s = scheduler.Waiting 428 So(s.String(), ShouldEqual, "waiting") 429 s = scheduler.Done 430 So(s.String(), ShouldEqual, "done") 431 }) 432 } 433 434 func TestGetNumWorkers(t *testing.T) { 435 Convey("Test setting the number of workers - default value", t, func() { 436 logger := log.NewLogger("debug", "logFile") 437 metrics := monitoring.NewMetricsServer(true, logger) 438 sch := scheduler.NewScheduler(config.New(), metrics, logger) 439 defer os.Remove("logFile") 440 So(sch.NumWorkers, ShouldEqual, runtime.NumCPU()*4) 441 }) 442 443 Convey("Test setting the number of workers - getting the value from config", t, func() { 444 cfg := config.New() 445 cfg.Scheduler = &config.SchedulerConfig{NumWorkers: 3} 446 logger := log.NewLogger("debug", "logFile") 447 metrics := monitoring.NewMetricsServer(true, logger) 448 sch := scheduler.NewScheduler(cfg, metrics, logger) 449 defer os.Remove("logFile") 450 So(sch.NumWorkers, ShouldEqual, 3) 451 }) 452 }