diff --git a/cmd/api/server.go b/cmd/api/server.go index 83697e6b..de35e0ac 100644 --- a/cmd/api/server.go +++ b/cmd/api/server.go @@ -6,6 +6,7 @@ import ( "net/http" "os" "os/signal" + "syscall" "time" "github.com/gin-gonic/gin" @@ -85,8 +86,8 @@ func run() error { runStartupHooks() srv := &http.Server{ - Addr: fmt.Sprintf("%s:%d", config.ApplicationConfig.Host, config.ApplicationConfig.Port), - Handler: sdk.Runtime.GetEngine(), + Addr: fmt.Sprintf("%s:%d", config.ApplicationConfig.Host, config.ApplicationConfig.Port), + Handler: sdk.Runtime.GetEngine(), ReadTimeout: time.Duration(config.ApplicationConfig.ReadTimeout) * time.Second, WriteTimeout: time.Duration(config.ApplicationConfig.WriterTimeout) * time.Second, } @@ -135,23 +136,68 @@ func run() error { fmt.Printf("- Local: http://localhost:%d/swagger/admin/index.html \r\n", config.ApplicationConfig.Port) fmt.Printf("- Network: %s://%s:%d/swagger/admin/index.html \r\n", "http", pkg.GetLocalHost(), config.ApplicationConfig.Port) fmt.Printf("%s Enter Control + C Shutdown Server \r\n", pkg.GetCurrentTimeStr()) - // 等待中断信号以优雅地关闭服务器(设置 5 秒的超时时间) - quit := make(chan os.Signal, 1) - signal.Notify(quit, os.Interrupt) - <-quit - ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) - defer cancel() + waitForStopSignal() + log.Info("Shutdown Server ... ") - - if err := srv.Shutdown(ctx); err != nil { - log.Fatal("Server Shutdown:", err) + if err := shutdownServer(srv, shutdownTimeout); err != nil { + // Not log.Fatal: that is an unconditional os.Exit(1), and Shutdown + // reports an error exactly when connections were still in flight - + // which is when the cleanup that follows matters most. + log.Error("Server Shutdown: ", err) } log.Info("Server exiting") return nil } +// shutdownTimeout is how long Shutdown waits for in-flight requests. It plus +// whatever cleanup follows has to stay inside the orchestrator's grace period +// - `docker stop` allows 10s by default before it sends SIGKILL. +const shutdownTimeout = 5 * time.Second + +// waitForStopSignal blocks until the process is asked to stop. +// +// SIGTERM is what actually arrives in production: `docker stop`, a Kubernetes +// pod deletion and `systemctl stop` all send it, and Go terminates the process +// immediately for a signal nobody listens for. Registering only os.Interrupt +// meant every graceful shutdown below this line was dead code outside a +// terminal. +// +// The disposition is restored before returning, so a second signal kills the +// process the default way. The channel keeps the notification we already took, +// so without this a stuck shutdown would swallow every further signal - once +// SIGTERM is registered there is no escape hatch left but SIGKILL. +func waitForStopSignal() os.Signal { + quit, disarm := armStopSignals() + defer disarm() + return <-quit +} + +// armStopSignals registers for the stop signals and returns the channel they +// arrive on together with the function that restores the default disposition. +// +// Registering is separate from waiting so a caller can arm before it announces +// that it is ready: a signal that arrives between the two is delivered to the +// default handler, which for both of these means the process dies without +// running any of this. +func armStopSignals() (<-chan os.Signal, func()) { + quit := make(chan os.Signal, 1) + signal.Notify(quit, os.Interrupt, syscall.SIGTERM) + return quit, func() { signal.Stop(quit) } +} + +// shutdownServer stops srv, giving in-flight requests up to timeout to finish. +// +// It returns the error instead of exiting on it. A caller that exits here skips +// its own cleanup, and Shutdown fails precisely when there was something left +// to clean up after. +func shutdownServer(srv *http.Server, timeout time.Duration) error { + ctx, cancel := context.WithTimeout(context.Background(), timeout) + defer cancel() + return srv.Shutdown(ctx) +} + // runStartupHooks runs the router registries and then the before callbacks. // // The package-level slice runs first and in its existing order, so a fork that diff --git a/cmd/api/signal_test.go b/cmd/api/signal_test.go new file mode 100644 index 00000000..604b27c3 --- /dev/null +++ b/cmd/api/signal_test.go @@ -0,0 +1,266 @@ +package api + +import ( + "fmt" + "net" + "net/http" + "os" + "os/exec" + "strings" + "syscall" + "testing" + "time" +) + +// 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 waitForStopSignal / 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" + markerReady = "CHILD-READY" + markerSignal = "CHILD-SIGNAL" + markerShutdown = "CHILD-SHUTDOWN-OK" + 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) + } + srv := &http.Server{Handler: http.NewServeMux()} + go func() { _ = srv.Serve(ln) }() + + if os.Getenv(childHangConn) == "1" { + c, err := net.Dial("tcp", ln.Addr().String()) + if err != nil { + fmt.Println("dial:", err) + os.Exit(5) + } + defer func() { _ = c.Close() }() + } + + // 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" { + // 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 + } + + 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) + } + 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")) + } + if err := cmd.Wait(); err != nil { + t.Fatalf("child exited with %v after a failed Shutdown, want a clean exit", err) + } +}