github.com/kontera-technologies/go-supervisor/v2@v2.1.0/supervisor_test.go (about) 1 package supervisor_test 2 3 import ( 4 "bytes" 5 "errors" 6 "io" 7 "io/ioutil" 8 "log" 9 "os" 10 "os/exec" 11 "path/filepath" 12 "reflect" 13 "runtime" 14 "strconv" 15 "strings" 16 "syscall" 17 "testing" 18 "time" 19 20 "github.com/fortytw2/leaktest" 21 22 su "github.com/kontera-technologies/go-supervisor/v2" 23 ) 24 25 func TestMain(m *testing.M) { 26 su.EnsureClosedTimeout = time.Millisecond * 10 27 os.Exit(m.Run()) 28 } 29 30 func safeStop(t *time.Timer) { 31 if !t.Stop() { 32 <-t.C 33 } 34 } 35 36 func runFor(t *testing.T, from, to int, f func(t *testing.T, i int)) { 37 t.Helper() 38 for i := from; i < to; i++ { 39 t.Run(strconv.Itoa(i), func(t *testing.T) { 40 t.Helper() 41 f(t, i) 42 }) 43 } 44 } 45 46 func fatalIfErr(tb testing.TB, err error) { 47 tb.Helper() 48 if err != nil { 49 tb.Fatal(err) 50 } 51 } 52 53 func assertExpectedEqualsActual(t *testing.T, expected, actual interface{}) { 54 t.Helper() 55 if !reflect.DeepEqual(expected, actual) { 56 t.Errorf("\n\tExpected: %q\n\tActual: %q", expected, actual) 57 } 58 } 59 60 func testDir(tb testing.TB) string { 61 testDir, err := filepath.Abs("testdata") 62 fatalIfErr(tb, err) 63 return testDir 64 } 65 66 func funcName() string { 67 pc, _, _, ok := runtime.Caller(1) 68 if !ok { 69 return "?" 70 } 71 72 fn := runtime.FuncForPC(pc) 73 return strings.TrimPrefix(fn.Name(), "github.com/kontera-technologies/go-supervisor/v2_test.") 74 } 75 76 // logProcessEvents is a helper function that registers an event notifier that 77 // will pass all events to the logger. 78 func logProcessEvents(tb testing.TB, p *su.Process) { 79 tb.Helper() 80 closeC := make(chan interface{}) 81 notifier := p.EventNotifier() 82 go func() { 83 tb.Helper() 84 for stop := false; !stop; { 85 select { 86 case x := <-notifier: 87 tb.Logf("%+v", x) 88 case <-closeC: 89 stop = true 90 } 91 } 92 }() 93 tb.Cleanup(func() { close(closeC) }) 94 } 95 96 func makeErrorParser(fromR io.Reader, parserSize int) su.ProduceFn { 97 p := su.MakeLineParser(fromR, parserSize) 98 return func() (*interface{}, error) { 99 raw, err := p() 100 if raw != nil { 101 var res interface{} 102 res = errors.New((*raw).(string)) 103 return &res, nil 104 } 105 return nil, err 106 } 107 } 108 109 // ensureProcessKilled logs a fatal error if the process isn't dead, and kills the process. 110 func ensureProcessKilled(tb testing.TB, pid int) { 111 tb.Helper() 112 signalErr := syscall.Kill(pid, syscall.Signal(0)) 113 if signalErr != syscall.Errno(3) { 114 tb.Errorf("child process (%d) is still running, killing it.", pid) 115 fatalIfErr(tb, syscall.Kill(pid, syscall.SIGKILL)) 116 } 117 } 118 119 func TestStderrMemoryLeak(t *testing.T) { 120 p := su.NewProcess(su.ProcessOptions{ 121 Id: funcName(), 122 Name: "./endless_errors.sh", 123 Dir: testDir(t), 124 OutputParser: su.MakeBytesParser, 125 ErrorParser: su.MakeBytesParser, 126 MaxSpawns: 1, 127 MaxSpawnAttempts: 1, 128 }) 129 130 origLogOut := log.Writer() 131 defer log.SetOutput(origLogOut) 132 logOut := bytes.NewBuffer([]byte{}) 133 log.SetOutput(logOut) 134 135 fatalIfErr(t, p.Start()) 136 137 time.Sleep(time.Millisecond * 20) 138 139 fatalIfErr(t, p.Stop()) 140 141 select { 142 case <-p.DoneNotifier(): 143 case <-time.After(time.Second): 144 t.Errorf("Timeout") 145 } 146 147 logOutStr := logOut.String() 148 if len(logOutStr) > 0 { 149 t.Errorf("Global logger was used - probably to print errors: \n%s", logOutStr) 150 } 151 } 152 153 func TestJsonParser(t *testing.T) { 154 p := su.NewProcess(su.ProcessOptions{ 155 Id: funcName(), 156 Name: "./endless_jsons.sh", 157 Dir: testDir(t), 158 OutputParser: su.MakeJsonLineParser, 159 ErrorParser: makeErrorParser, 160 MaxSpawns: 1, 161 Out: make(chan *interface{}, 5), 162 }) 163 164 expected := map[string]interface{}{ 165 "foo": "bar", 166 "quo": []interface{}{"quz", float64(1), false}, 167 } 168 169 fatalIfErr(t, p.Start()) 170 defer p.Stop() 171 172 time.AfterFunc(time.Millisecond*30, func() { 173 fatalIfErr(t, p.Stop()) 174 }) 175 176 runFor(t, 0, 3, func(t *testing.T, i int) { 177 select { 178 case v := <-p.Stdout(): 179 assertExpectedEqualsActual(t, expected, *v) 180 case <-time.After(time.Millisecond * 30): 181 t.Error("Expected output.") 182 } 183 }) 184 185 select { 186 case v := <-p.Stdout(): 187 t.Errorf("Unexpected output - %#v", *v) 188 case <-time.After(time.Millisecond * 20): 189 } 190 } 191 192 func TestBadJsonOutput(t *testing.T) { 193 out := bytes.NewReader([]byte(`{"a":"b"} 194 2019/08/21 195 13:43:24 196 invalid character '}' 197 {"c":"d"}{"c":"d"} 198 {"c":"d"}`)) 199 tmp := su.MakeJsonLineParser(out, 4096) 200 p := func() *interface{} { 201 a, _ := tmp() 202 return a 203 } 204 205 assertExpectedEqualsActual(t, map[string]interface{}{"a": "b"}, *p()) 206 assertExpectedEqualsActual(t, float64(2019), *p()) 207 assertExpectedEqualsActual(t, (*interface{})(nil), p()) 208 assertExpectedEqualsActual(t, float64(13), *p()) 209 assertExpectedEqualsActual(t, (*interface{})(nil), p()) 210 assertExpectedEqualsActual(t, (*interface{})(nil), p()) 211 assertExpectedEqualsActual(t, map[string]interface{}{"c": "d"}, *p()) 212 assertExpectedEqualsActual(t, map[string]interface{}{"c": "d"}, *p()) 213 assertExpectedEqualsActual(t, map[string]interface{}{"c": "d"}, *p()) 214 assertExpectedEqualsActual(t, (*interface{})(nil), p()) 215 } 216 217 func BenchmarkBadJsonOutput(b *testing.B) { 218 219 } 220 221 func TestProcess_Start(t *testing.T) { 222 p := su.NewProcess(su.ProcessOptions{ 223 Id: funcName(), 224 Name: "./greet_with_error.sh", 225 Args: []string{"Hello"}, 226 Dir: testDir(t), 227 OutputParser: su.MakeLineParser, 228 ErrorParser: makeErrorParser, 229 MaxSpawns: 1, 230 Out: make(chan *interface{}, 1), 231 Err: make(chan *interface{}, 1), 232 }) 233 234 fatalIfErr(t, p.Start()) 235 defer p.Stop() 236 237 x := []byte("world\n") 238 select { 239 case p.Input() <- x: 240 case <-time.After(time.Millisecond): 241 t.Error("Input wasn't consumed in 1 millisecond") 242 } 243 244 select { 245 case out := <-p.Stdout(): 246 assertExpectedEqualsActual(t, "Hello world", *out) 247 case <-time.After(time.Millisecond * 200): 248 t.Error("No output in 200ms") 249 } 250 251 select { 252 case v := <-p.Stderr(): 253 assertExpectedEqualsActual(t, "Bye world", (*v).(error).Error()) 254 case <-time.After(time.Millisecond * 200): 255 t.Error("No error in 200ms") 256 } 257 } 258 259 func TestMakeLineParser(t *testing.T) { 260 cmd := exec.Command("./endless.sh") 261 cmd.Dir = testDir(t) 262 out, _ := cmd.StdoutPipe() 263 _ = cmd.Start() 264 c := make(chan *interface{}) 265 go func() { 266 x := su.MakeLineParser(out, 0) 267 for a, _ := x(); a != nil; a, _ = x() { 268 c <- a 269 } 270 close(c) 271 }() 272 time.AfterFunc(time.Second, func() { 273 _ = cmd.Process.Kill() 274 }) 275 276 runFor(t, 0, 10, func(t *testing.T, i int) { 277 select { 278 case x := <-c: 279 if x == nil { 280 t.Error("unexpected nil") 281 return 282 } 283 assertExpectedEqualsActual(t, "foo", *x) 284 case <-time.After(time.Millisecond * 20): 285 t.Error("Expected output before 20ms pass.") 286 } 287 }) 288 } 289 290 func TestProcess_Signal(t *testing.T) { 291 p := su.NewProcess(su.ProcessOptions{ 292 Id: funcName(), 293 Name: "./endless.sh", 294 Dir: testDir(t), 295 Out: make(chan *interface{}, 10), 296 OutputParser: su.MakeLineParser, 297 ErrorParser: makeErrorParser, 298 }) 299 300 fatalIfErr(t, p.Start()) 301 defer p.Stop() 302 pid := p.Pid() 303 304 c := make(chan bool) 305 time.AfterFunc(time.Millisecond*70, func() { 306 fatalIfErr(t, syscall.Kill(-p.Pid(), syscall.SIGINT)) 307 c <- true 308 }) 309 310 runFor(t, 0, 5, func(t *testing.T, i int) { 311 select { 312 case out := <-p.Stdout(): 313 if *out != "foo" { 314 t.Errorf(`Expected: "foo", received: "%s"`, *out) 315 } 316 case err := <-p.Stderr(): 317 t.Error("Unexpected error:", err) 318 case <-time.After(time.Millisecond * 30): 319 t.Error("Expected output in channel") 320 } 321 }) 322 323 <-c 324 time.Sleep(time.Millisecond * 10) 325 ensureProcessKilled(t, pid) 326 } 327 328 func TestProcess_Close(t *testing.T) { 329 p := su.NewProcess(su.ProcessOptions{ 330 Id: funcName(), 331 Name: "./trap.sh", 332 Args: []string{"endless.sh"}, 333 Dir: testDir(t), 334 OutputParser: su.MakeLineParser, 335 ErrorParser: makeErrorParser, 336 EventNotifier: make(chan su.Event, 10), 337 MaxInterruptAttempts: 1, 338 MaxTerminateAttempts: 2, 339 TerminationGraceTimeout: time.Millisecond, 340 }) 341 342 procClosedC := make(chan error) 343 fatalIfErr(t, p.Start()) 344 time.AfterFunc(time.Millisecond*20, func() { 345 procClosedC <- p.Stop() 346 }) 347 348 var err error 349 var childPid int 350 351 select { 352 case v := <-p.Stderr(): 353 childPid, err = strconv.Atoi((*v).(error).Error()) 354 if err != nil { 355 t.Fatal("Expected child process id in error channel. Instead received:", (*v).(error).Error()) 356 } 357 case <-time.After(time.Millisecond * 10): 358 t.Fatal("Expected child process id in error channel in 100 milliseconds") 359 } 360 361 t.Run("<-procClosedC", func(t *testing.T) { 362 fatalIfErr(t, <-procClosedC) 363 }) 364 365 t.Run("trapped signals", func(t *testing.T) { 366 errs := map[string]string{ 367 "InterruptError": "interrupt signal failed - 1 attempts", 368 "TerminateError": "terminate signal failed - 2 attempts", 369 } 370 371 for i := 0; i < 10 && len(errs) > 0; i++ { 372 select { 373 case ev := <-p.EventNotifier(): 374 if !strings.HasSuffix(ev.Code, "Error") { 375 continue 376 } 377 assertExpectedEqualsActual(t, errs[ev.Code], ev.Message) 378 delete(errs, ev.Code) 379 default: 380 } 381 } 382 for code, err := range errs { 383 t.Errorf(`expected a %s event - "%s"`, code, err) 384 } 385 }) 386 387 time.Sleep(time.Millisecond * 15) 388 ensureProcessKilled(t, childPid) 389 } 390 391 func TestProcess_RespawnOnFailedExit(t *testing.T) { 392 p := su.NewProcess(su.ProcessOptions{ 393 Id: funcName(), 394 Name: "./error.sh", 395 Dir: testDir(t), 396 OutputParser: su.MakeLineParser, 397 ErrorParser: su.MakeLineParser, 398 Err: make(chan *interface{}, 3), 399 MaxSpawns: 3, 400 MaxRespawnBackOff: time.Millisecond, 401 }) 402 403 fatalIfErr(t, p.Start()) 404 defer p.Stop() 405 406 runFor(t, 0, 3, func(t *testing.T, i int) { 407 select { 408 case out := <-p.Stdout(): 409 t.Errorf("Unexpected output: %#v", out) 410 case v := <-p.Stderr(): 411 assertExpectedEqualsActual(t, "Bye world", *v) 412 case <-time.After(time.Millisecond * 3000): 413 t.Error("Expected error within 3000ms") 414 return 415 } 416 }) 417 418 select { 419 case out := <-p.Stdout(): 420 t.Errorf("Unexpected output: %#v", out) 421 case v := <-p.Stderr(): 422 t.Errorf("Unexpected error: %#v", *v) 423 case <-time.After(time.Millisecond * 500): 424 } 425 } 426 427 func TestProcess_NoRespawnOnSuccessExit(t *testing.T) { 428 runtime.Caller(0) 429 p := su.NewProcess(su.ProcessOptions{ 430 Id: funcName(), 431 Name: "./echo.sh", 432 Dir: testDir(t), 433 OutputParser: su.MakeLineParser, 434 ErrorParser: makeErrorParser, 435 }) 436 437 fatalIfErr(t, p.Start()) 438 defer p.Stop() 439 440 select { 441 case out := <-p.Stdout(): 442 assertExpectedEqualsActual(t, "Hello world", *out) 443 case <-time.After(time.Millisecond * 150): 444 t.Error("No output in 150 milliseconds") 445 } 446 447 select { 448 case out := <-p.Stdout(): 449 t.Errorf("Unexpected output: %s", *out) 450 case <-time.After(time.Millisecond * 10): 451 } 452 } 453 454 func TestCalcBackOff(t *testing.T) { 455 p1 := su.NewProcess(su.ProcessOptions{Id: funcName() + "-1"}) 456 p2 := su.NewProcess(su.ProcessOptions{Id: funcName() + "-2"}) 457 458 for i := 0; i < 5; i++ { 459 a, b := p1.CalcBackOff(i, time.Second, time.Minute), p2.CalcBackOff(i, time.Second, time.Minute) 460 if a == b { 461 t.Errorf("2 identical results for CalcBackOff(%d, time.Minute): %v", i, a) 462 } 463 } 464 } 465 466 func TestProcess_Restart(t *testing.T) { 467 defer leaktest.Check(t)() 468 timer := time.NewTimer(0) 469 safeStop(timer) 470 471 // initialGoroutines := runtime.NumGoroutine() 472 p := su.NewProcess(su.ProcessOptions{ 473 Id: funcName(), 474 Name: "./endless.sh", 475 Dir: testDir(t), 476 OutputParser: su.MakeLineParser, 477 ErrorParser: makeErrorParser, 478 Out: make(chan *interface{}, 5), 479 IdleTimeout: time.Millisecond * 30, 480 MaxSpawns: 2, 481 MaxRespawnBackOff: time.Microsecond * 100, 482 TerminationGraceTimeout: time.Millisecond, 483 }) 484 485 fatalIfErr(t, p.Start()) 486 defer p.Stop() 487 488 numGoroutines := -1 489 490 runFor(t, 0, 3, func(t *testing.T, i int) { 491 timer.Reset(time.Millisecond * 20) 492 if numGoroutines == -1 { 493 numGoroutines = runtime.NumGoroutine() 494 } 495 select { 496 case out := <-p.Stdout(): 497 if *out != "foo" { 498 t.Errorf(`Expected: "foo", received: "%s"`, *out) 499 } 500 case err := <-p.Stderr(): 501 t.Error("Unexpected error:", err) 502 case <-timer.C: 503 t.Error("Expected output in channel") 504 return 505 } 506 safeStop(timer) 507 }) 508 509 fatalIfErr(t, p.Restart()) 510 511 t.Run("SIGINT received", func(t *testing.T) { 512 if state := p.LastProcessState(); state != nil { 513 raw := state.Sys() 514 waitStatus, ok := raw.(syscall.WaitStatus) 515 if !ok { 516 t.Fatalf("Process.LastError().Sys() should be of type syscall.WaitStatus, %q received", raw) 517 } else if waitStatus.Signal() != syscall.SIGINT { 518 t.Errorf("Expected %#v, %#v signal received", syscall.SIGINT.String(), waitStatus.Signal().String()) 519 } 520 } 521 }) 522 523 runFor(t, 3, 6, func(t *testing.T, i int) { 524 timer.Reset(time.Millisecond * 20) 525 select { 526 case out := <-p.Stdout(): 527 if *out != "foo" { 528 t.Errorf(`Expected: "foo", received: "%s"`, *out) 529 } 530 case err := <-p.Stderr(): 531 t.Error("Unexpected error:", err) 532 case <-timer.C: 533 t.Error("Expected output in channel within 120ms") 534 return 535 } 536 safeStop(timer) 537 }) 538 539 _ = p.Restart() 540 541 t.Run("MaxSpawns reached", func(t *testing.T) { 542 timer.Reset(time.Millisecond * 24) 543 select { 544 case out := <-p.Stdout(): 545 t.Error("Unexpected output:", *out) 546 case err := <-p.Stderr(): 547 t.Error("Unexpected error:", err) 548 case <-timer.C: 549 return 550 } 551 safeStop(timer) 552 }) 553 time.Sleep(time.Second) 554 } 555 556 // test_timings_compressed_data can be used to test the performance of this library. 557 func test_timings_compressed_data(t *testing.T) { 558 runtime.GOMAXPROCS(runtime.NumCPU()) 559 560 f, err := os.Open("testdata/ipsum.zlib") 561 fatalIfErr(t, err) 562 content, err := ioutil.ReadAll(f) 563 fatalIfErr(t, err) 564 565 producer := su.NewProcess(su.ProcessOptions{ 566 Id: funcName(), 567 Name: "./zlib.sh", 568 Dir: testDir(t), 569 OutputParser: su.MakeLineParser, 570 ErrorParser: su.MakeLineParser, 571 MaxSpawnAttempts: 1, 572 ParserBufferSize: 170000, 573 }) 574 575 fatalIfErr(t, producer.Start()) 576 577 stop := make(chan bool) 578 pDone := make(chan bool) 579 580 prodInNum := int64(0) 581 prodOutNum := int64(0) 582 583 go func() { 584 for { 585 select { 586 case <-stop: 587 log.Println("prodInNum", prodInNum) 588 return 589 case <-time.After(time.Microsecond): 590 producer.Input() <- content 591 prodInNum++ 592 } 593 } 594 }() 595 596 go func() { 597 for { 598 select { 599 case <-stop: 600 log.Println("prodOutNum", prodOutNum) 601 return 602 case <-producer.Stdout(): 603 prodOutNum++ 604 } 605 } 606 }() 607 608 go func() { 609 <-stop 610 _ = producer.Stop() 611 close(pDone) 612 }() 613 614 time.AfterFunc(time.Second*10, func() { 615 close(stop) 616 }) 617 618 <-pDone 619 620 log.Println(prodInNum, prodOutNum) 621 } 622 623 // test_timings can be used to test the performance of this library. 624 func test_timings(t *testing.T) { 625 runtime.GOMAXPROCS(runtime.NumCPU()) 626 627 f, err := os.Open("testdata/ipsum.txt") 628 fatalIfErr(t, err) 629 630 ipsum, err := ioutil.ReadAll(f) 631 fatalIfErr(t, err) 632 ipsum = append(ipsum, '\n') 633 634 producer := su.NewProcess(su.ProcessOptions{ 635 Id: funcName(), 636 Name: "./producer.sh", 637 Dir: testDir(t), 638 OutputParser: su.MakeBytesParser, 639 ErrorParser: su.MakeLineParser, 640 ParserBufferSize: 170000, 641 }) 642 incrementer := su.NewProcess(su.ProcessOptions{ 643 Id: funcName(), 644 Name: "./incrementer.sh", 645 Dir: testDir(t), 646 OutputParser: su.MakeBytesParser, 647 ErrorParser: su.MakeLineParser, 648 ParserBufferSize: 170000, 649 }) 650 651 fatalIfErr(t, producer.Start()) 652 fatalIfErr(t, incrementer.Start()) 653 654 stop := make(chan bool) 655 pDone := make(chan bool) 656 iDone := make(chan bool) 657 658 prodInNum := int64(0) 659 prodOutNum := int64(0) 660 incOutNum := int64(0) 661 662 go func() { 663 for { 664 select { 665 case <-stop: 666 log.Println("prodInNum", prodInNum) 667 return 668 case <-time.After(time.Microsecond * 50): 669 producer.Input() <- ipsum 670 prodInNum++ 671 } 672 } 673 }() 674 675 go func() { 676 for { 677 select { 678 case <-stop: 679 log.Println("prodOutNum", prodOutNum) 680 return 681 case msg := <-producer.Stdout(): 682 incrementer.Input() <- (*msg).([]byte) 683 prodOutNum++ 684 } 685 } 686 }() 687 688 go func() { 689 for { 690 select { 691 case <-stop: 692 log.Println("incOutNum", incOutNum) 693 return 694 case <-incrementer.Stdout(): 695 incOutNum++ 696 } 697 } 698 }() 699 700 go func() { 701 <-stop 702 _ = producer.Stop() 703 close(pDone) 704 }() 705 go func() { 706 <-stop 707 _ = incrementer.Stop() 708 close(iDone) 709 }() 710 711 time.AfterFunc(time.Second*10, func() { 712 close(stop) 713 }) 714 715 <-iDone 716 <-pDone 717 718 log.Println(prodInNum, prodOutNum, incOutNum) 719 } 720 721 func TestMonitorRunTimeout(t *testing.T) { 722 heartbeat, isMonitorClosed, stopC := make(chan bool), make(chan bool), make(chan bool) 723 result := make(chan string) 724 resEvent := make(chan string) 725 726 stopF := func() error { 727 result <- "Stopped" 728 return nil 729 } 730 eventNotify := func(event string, message ...interface{}) { 731 resEvent <- event 732 } 733 go su.MonitorHeartBeat(20*time.Millisecond, 10*time.Millisecond, heartbeat, isMonitorClosed, stopC, stopF, eventNotify) 734 time.Sleep(20 * time.Millisecond) 735 assertExpectedEqualsActual(t, <-resEvent, "RunTimePassed") 736 assertExpectedEqualsActual(t, <-result, "Stopped") 737 }