package api import ( "context" "fmt" "net" "net/http" "os" "os/exec" "strings" "syscall" "testing" "time" "github.com/go-admin-team/go-admin-core/v2/sdk" ) // The signal path cannot be exercised in-process: delivering a signal to the // test binary would race with the test framework, and the disposition changes // are global. So the test re-executes itself as a child, and the child runs the // same armStopSignals / shutdownServer the server does. // // The child deliberately serves an empty http.Server rather than the real one: // this repository's CI has no database (.github/workflows/go.yml runs neither // MySQL nor a sqlite-tagged build), and none of what is under test needs one. const ( childEnv = "GO_ADMIN_SIGNAL_CHILD" childStuckEnv = "GO_ADMIN_SIGNAL_CHILD_STUCK" childHangConn = "GO_ADMIN_SIGNAL_CHILD_HANGCONN" childSlowCleanup = "GO_ADMIN_SIGNAL_CHILD_SLOWCLEANUP" markerReady = "CHILD-READY" markerSignal = "CHILD-SIGNAL" markerShutdown = "CHILD-SHUTDOWN-OK" markerCleanup = "CHILD-CLEANUP-RAN" markerExiting = "CHILD-EXITING" ) // TestSignalChild is the child process. It is skipped in a normal run. func TestSignalChild(t *testing.T) { if os.Getenv(childEnv) != "1" { t.Skip("child process entry point") } ln, err := net.Listen("tcp", "127.0.0.1:0") if err != nil { fmt.Println("listen:", err) os.Exit(3) } // accepted fires once the server has taken a connection off the listener. // Dialling is not enough: Shutdown only waits for connections the server // has already accepted, so calling it between the dial and the accept // finds nothing to wait for and returns immediately. accepted := make(chan struct{}, 1) srv := &http.Server{ Handler: http.NewServeMux(), ConnState: func(_ net.Conn, state http.ConnState) { if state == http.StateNew { select { case accepted <- struct{}{}: default: } } }, } go func() { _ = srv.Serve(ln) }() // A BeforeExit callback, registered the way a module would. What the tests // below care about is whether it runs at all - after a Shutdown that // failed, and after its own budget has been spent. cleanupBudget := cleanupTimeout sdk.Runtime.SetShutdown(func(ctx context.Context) { if os.Getenv(childSlowCleanup) == "1" { // Outlasts the budget on purpose, and does not consult ctx - // which is the case the contract is explicit about: what the // context bounds is the wait, not the work. time.Sleep(2 * time.Second) } fmt.Println(markerCleanup) os.Stdout.Sync() }) if os.Getenv(childSlowCleanup) == "1" { cleanupBudget = 300 * time.Millisecond } // Arm before announcing readiness. Doing it the other way round leaves a // window in which the parent's signal reaches the default handler and // kills the child before any of this runs - which is exactly the failure // this whole change is about, so the test must not reproduce it by // accident. quit, disarm := armStopSignals() fmt.Println(markerReady) os.Stdout.Sync() sig := <-quit disarm() fmt.Println(markerSignal, sig) os.Stdout.Sync() if os.Getenv(childStuckEnv) == "1" { // Stand in for a cleanup hook that never finishes. The point of // restoring the signal disposition is that a second signal still // reaches the default handler and kills this. time.Sleep(2 * time.Minute) } timeout := shutdownTimeout if os.Getenv(childHangConn) == "1" { // Dialled here, not at start-up. net/http stops counting a StateNew // connection against Shutdown once it is more than five seconds old, // so a connection opened before the wait would age out on a slow CI // run and Shutdown would succeed - leaving the test asserting nothing. c, err := net.Dial("tcp", ln.Addr().String()) if err != nil { fmt.Println("dial:", err) os.Exit(5) } defer func() { _ = c.Close() }() // And wait for the accept, for the opposite reason: an unaccepted // connection is not one Shutdown waits for either. select { case <-accepted: case <-time.After(10 * time.Second): fmt.Println("the server never accepted the stalling connection") os.Exit(6) } // A connection that has sent nothing keeps Shutdown busy: net/http // only treats a StateNew connection as idle once it is more than five // seconds old. A short budget makes the timeout deterministic without // waiting out the real one. timeout = 300 * time.Millisecond } sdk.Runtime.BeginShutdown() if err := shutdownServer(srv, timeout); err != nil { // Deliberately not fatal, and deliberately not a bare return: the // point is that whatever follows still runs. fmt.Println("shutdown error:", err) } else { fmt.Println(markerShutdown) } if err := runShutdownHooks(cleanupBudget); err != nil { fmt.Println("cleanup error:", err) } fmt.Println(markerExiting) os.Stdout.Sync() } func startChild(t *testing.T, stuck bool, extraEnv ...string) (*exec.Cmd, *os.File, chan string) { t.Helper() r, w, err := os.Pipe() if err != nil { t.Fatalf("pipe: %v", err) } cmd := exec.Command(os.Args[0], "-test.run=TestSignalChild", "-test.v") cmd.Env = append(os.Environ(), childEnv+"=1") if stuck { cmd.Env = append(cmd.Env, childStuckEnv+"=1") } cmd.Env = append(cmd.Env, extraEnv...) cmd.Stdout = w cmd.Stderr = w if err := cmd.Start(); err != nil { t.Fatalf("start child: %v", err) } _ = w.Close() lines := make(chan string, 64) go func() { defer close(lines) buf := make([]byte, 4096) var acc strings.Builder for { n, err := r.Read(buf) if n > 0 { acc.Write(buf[:n]) for { s := acc.String() i := strings.IndexByte(s, '\n') if i < 0 { break } lines <- s[:i] acc.Reset() acc.WriteString(s[i+1:]) } } if err != nil { if acc.Len() > 0 { lines <- acc.String() } return } } }() t.Cleanup(func() { _ = cmd.Process.Kill() _, _ = cmd.Process.Wait() _ = r.Close() }) return cmd, r, lines } // await drains lines until one contains want, or the deadline passes. It // returns everything it saw, so a failure says what the child actually did. func await(t *testing.T, lines chan string, want string, d time.Duration) []string { t.Helper() var seen []string deadline := time.After(d) for { select { case l, ok := <-lines: if !ok { t.Fatalf("child output ended before %q; saw:\n%s", want, strings.Join(seen, "\n")) } seen = append(seen, l) if strings.Contains(l, want) { return seen } case <-deadline: t.Fatalf("timed out waiting for %q; saw:\n%s", want, strings.Join(seen, "\n")) } } } // Acceptance 19. Registering only os.Interrupt meant SIGTERM - the signal // `docker stop`, Kubernetes and systemd all send - terminated the process // before any of the shutdown path ran. Both must now reach it. func TestBothSignalsRunTheShutdownPath(t *testing.T) { for _, tc := range []struct { name string sig syscall.Signal }{ {"SIGINT", syscall.SIGINT}, {"SIGTERM", syscall.SIGTERM}, } { t.Run(tc.name, func(t *testing.T) { cmd, _, lines := startChild(t, false) await(t, lines, markerReady, 30*time.Second) if err := cmd.Process.Signal(tc.sig); err != nil { t.Fatalf("signal: %v", err) } await(t, lines, markerSignal, 10*time.Second) await(t, lines, markerShutdown, 10*time.Second) await(t, lines, markerExiting, 10*time.Second) if err := cmd.Wait(); err != nil { t.Fatalf("child exited with %v, want a clean exit", err) } }) } } // Acceptance 20. quit is a buffered channel and signal.Notify stays armed, so // without restoring the disposition a second signal only refills the buffer: // once SIGTERM is registered, a shutdown that hangs could not be interrupted by // anything short of SIGKILL. func TestASecondSignalStillKillsAStuckShutdown(t *testing.T) { cmd, _, lines := startChild(t, true) await(t, lines, markerReady, 30*time.Second) if err := cmd.Process.Signal(syscall.SIGTERM); err != nil { t.Fatalf("first signal: %v", err) } await(t, lines, markerSignal, 10*time.Second) // The child is now inside a cleanup that will not finish on its own. if err := cmd.Process.Signal(syscall.SIGTERM); err != nil { t.Fatalf("second signal: %v", err) } done := make(chan error, 1) go func() { done <- cmd.Wait() }() select { case err := <-done: if err == nil { t.Fatal("child exited cleanly; it was supposed to be killed by the second signal") } case <-time.After(15 * time.Second): t.Fatal("the second signal did not kill a stuck shutdown - the escape hatch is gone") } } // Acceptance 21. srv.Shutdown reports an error exactly when connections were // still in flight, and the old code answered that with log.Fatal - an // unconditional os.Exit(1). Everything after it, which is where the cleanup // hooks will hang, never ran. A failed Shutdown must not end the process. func TestShutdownTimeoutDoesNotStopWhatFollows(t *testing.T) { cmd, _, lines := startChild(t, false, childHangConn+"=1") await(t, lines, markerReady, 30*time.Second) if err := cmd.Process.Signal(syscall.SIGTERM); err != nil { t.Fatalf("signal: %v", err) } await(t, lines, markerSignal, 10*time.Second) seen := await(t, lines, markerExiting, 20*time.Second) var timedOut bool for _, l := range seen { if strings.Contains(l, "shutdown error:") { timedOut = true } } if !timedOut { t.Fatalf("Shutdown did not time out, so this test proves nothing; saw:\n%s", strings.Join(seen, "\n")) } var cleaned bool for _, l := range seen { if strings.Contains(l, markerCleanup) { cleaned = true } } if !cleaned { t.Fatalf("the BeforeExit callback did not run after a failed Shutdown; saw:\n%s", strings.Join(seen, "\n")) } if err := cmd.Wait(); err != nil { t.Fatalf("child exited with %v after a failed Shutdown, want a clean exit", err) } } // A callback that outlasts its budget must not take the process with it, and // must not be waited for: RunShutdown reports the deadline and returns, the // callback carries on, and the process still exits cleanly. This is the half of // the contract that is easy to get backwards - the context bounds the wait, not // the work, because Go cannot cancel a function that does not check for it. func TestACleanupThatOutlastsItsBudgetIsAbandonedNotAwaited(t *testing.T) { cmd, _, lines := startChild(t, false, childSlowCleanup+"=1") await(t, lines, markerReady, 30*time.Second) if err := cmd.Process.Signal(syscall.SIGTERM); err != nil { t.Fatalf("signal: %v", err) } await(t, lines, markerSignal, 10*time.Second) // The budget is 300ms and the callback sleeps two seconds. If RunShutdown // waited for it, this marker would not arrive for two seconds; the one // second here is what makes "abandoned, not awaited" the thing asserted. seen := await(t, lines, markerExiting, 1*time.Second) var reported bool for _, l := range seen { if strings.Contains(l, "cleanup error:") { reported = true } if strings.Contains(l, markerCleanup) { t.Fatalf("the slow callback finished before the process moved on, so nothing was abandoned; saw:\n%s", strings.Join(seen, "\n")) } } if !reported { t.Fatalf("RunShutdown returned no error for a callback that outlasted the budget; saw:\n%s", strings.Join(seen, "\n")) } if err := cmd.Wait(); err != nil { t.Fatalf("child exited with %v, want a clean exit despite the abandoned callback", err) } }