From 4f767e7c521d02f6b0c7c5e31875868b63e7cb0f Mon Sep 17 00:00:00 2001 From: adababys <8872412+adababys@users.noreply.github.com> Date: Fri, 16 Oct 2026 18:18:54 +0800 Subject: [PATCH] fix(api,shared): don't report server-initiated cancellation as client-closed MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The request middleware decided a request was client-closed (499) from a bare errors.Is(cancelCause, context.Canceled). But context.Canceled only means some context in the chain was cancelled, not that the client disconnected. The API server roots every request at a base context whose cancel() fires on process teardown, so an in-flight request cut by shutdown saw plain context.Canceled and was logged/recorded as 499 — mislabeling the server's own teardown as client behaviour. - shared/middleware: add ErrServerShuttingDown, a cancel cause a server sets on the parent of every request context on teardown, alongside the existing ErrRequestTimeout. Add IsClientDisconnect / IsServerShutdown classifiers that check the server-side causes first (both satisfy errors.Is(_, Canceled) once they propagate as a cancellation). - logging / metrics / tracing middleware: classify via the helpers. A request cut by server teardown keeps its real status and is tagged server_shutdown rather than being counted as a 499 client disconnect. - api/main: root the request context with context.WithCancelCause and cancel it with ErrServerShuttingDown, so the cause propagates through http.Server BaseContext and the per-request timeout wrapper into the middleware. Fixes #3685 --- packages/api/main.go | 8 ++- packages/shared/pkg/middleware/logging.go | 10 ++- .../pkg/middleware/otel/metrics/middleware.go | 8 +-- .../pkg/middleware/otel/tracing/middleware.go | 8 ++- packages/shared/pkg/middleware/timeout.go | 35 ++++++++++ .../shared/pkg/middleware/timeout_test.go | 64 +++++++++++++++++++ 6 files changed, 122 insertions(+), 11 deletions(-) diff --git a/packages/api/main.go b/packages/api/main.go index 91d7185279..01a4d548d6 100644 --- a/packages/api/main.go +++ b/packages/api/main.go @@ -270,8 +270,12 @@ func NewGinServer(ctx context.Context, config cfg.Config, tel *telemetry.Client, } func run() int { - ctx, cancel := context.WithCancel(context.Background()) // root context - defer cancel() + ctx, cancel := context.WithCancelCause(context.Background()) // root context + // Cancelling with ErrServerShuttingDown as the cause lets the request + // middleware tell a request cut by teardown (this cancel propagating + // through http.Server BaseContext) apart from a client disconnect, so the + // former is not logged/recorded as a 499 client-closed request. + defer cancel(sharedmiddleware.ErrServerShuttingDown) // TODO: additional improvements to signal handling/shutdown: // - provide access to root context in the signal handling diff --git a/packages/shared/pkg/middleware/logging.go b/packages/shared/pkg/middleware/logging.go index 5412e5e2cc..96efac4d03 100644 --- a/packages/shared/pkg/middleware/logging.go +++ b/packages/shared/pkg/middleware/logging.go @@ -1,7 +1,6 @@ package middleware import ( - "context" "errors" "net/http" "regexp" @@ -82,9 +81,14 @@ func LoggingMiddleware(logger logger.Logger, conf Config) gin.HandlerFunc { status := c.Writer.Status() cause := CancelCause(c) - if errors.Is(cause, ErrRequestTimeout) { + switch { + case errors.Is(cause, ErrRequestTimeout): fields = append(fields, zap.Bool("request_timeout", true)) - } else if errors.Is(cause, context.Canceled) { + case IsServerShutdown(cause): + // The server cut this request on teardown; it is not the + // client closing the connection. + fields = append(fields, zap.Bool("server_shutdown", true)) + case IsClientDisconnect(cause): status = StatusClientClosedRequest // 499 fields = append(fields, zap.Bool("client_canceled", true)) } diff --git a/packages/shared/pkg/middleware/otel/metrics/middleware.go b/packages/shared/pkg/middleware/otel/metrics/middleware.go index f4e7da0f23..24b2c5478a 100644 --- a/packages/shared/pkg/middleware/otel/metrics/middleware.go +++ b/packages/shared/pkg/middleware/otel/metrics/middleware.go @@ -1,8 +1,6 @@ package metrics import ( - "context" - "errors" "fmt" "strings" "time" @@ -86,8 +84,10 @@ func Middleware(meterProvider metric.MeterProvider, service string, options ...O ) code := ginCtx.Writer.Status() - if errors.Is(sharedmiddleware.CancelCause(ginCtx), context.Canceled) { - // 499 is the nginx convention for "client closed request before server responded" + if sharedmiddleware.IsClientDisconnect(sharedmiddleware.CancelCause(ginCtx)) { + // 499 is the nginx convention for "client closed request before server responded". + // A request cut by server teardown keeps its real status rather than being + // counted as a client disconnect. code = sharedmiddleware.StatusClientClosedRequest } diff --git a/packages/shared/pkg/middleware/otel/tracing/middleware.go b/packages/shared/pkg/middleware/otel/tracing/middleware.go index 9594e9d155..5480401952 100644 --- a/packages/shared/pkg/middleware/otel/tracing/middleware.go +++ b/packages/shared/pkg/middleware/otel/tracing/middleware.go @@ -122,9 +122,13 @@ func Middleware(tracerProvider oteltrace.TracerProvider, service string) gin.Han status := c.Writer.Status() cause := sharedmiddleware.CancelCause(c) - if errors.Is(cause, sharedmiddleware.ErrRequestTimeout) { + switch { + case errors.Is(cause, sharedmiddleware.ErrRequestTimeout): span.SetAttributes(attribute.Bool("request.timeout", true)) - } else if errors.Is(cause, context.Canceled) { + case sharedmiddleware.IsServerShutdown(cause): + // Cut by server teardown, not the client; keep the real status. + span.SetAttributes(attribute.Bool("server.shutdown", true)) + case sharedmiddleware.IsClientDisconnect(cause): status = sharedmiddleware.StatusClientClosedRequest span.SetAttributes(attribute.Bool("client.canceled", true)) } diff --git a/packages/shared/pkg/middleware/timeout.go b/packages/shared/pkg/middleware/timeout.go index 7c8546567c..797a1076f3 100644 --- a/packages/shared/pkg/middleware/timeout.go +++ b/packages/shared/pkg/middleware/timeout.go @@ -14,6 +14,41 @@ import ( // errors.Is(CancelCause(c), middleware.ErrRequestTimeout) var ErrRequestTimeout = errors.New("request timeout exceeded") +// ErrServerShuttingDown is the cancel cause a server sets on the parent of +// every request context when it tears down, so an in-flight request cut by +// the shutdown is not mistaken for a client disconnect. Wire it as the cause +// of the http.Server BaseContext: +// +// ctx, cancel := context.WithCancelCause(context.Background()) +// defer cancel(middleware.ErrServerShuttingDown) +// // server.BaseContext returns ctx +// +// The cause propagates through net/http into r.Context() and through the +// per-request timeout wrapper below, so IsServerShutdown(CancelCause(c)) +// reports it after the handler returns. +var ErrServerShuttingDown = errors.New("server shutting down") + +// IsClientDisconnect reports whether cause is a client that closed the +// connection before the server responded — a bare context.Canceled that is +// neither the per-request timeout nor a server teardown. The two server-side +// causes are checked first because they also satisfy errors.Is(_, Canceled) +// once they propagate as a context cancellation. +func IsClientDisconnect(cause error) bool { + if cause == nil { + return false + } + if errors.Is(cause, ErrRequestTimeout) || errors.Is(cause, ErrServerShuttingDown) { + return false + } + + return errors.Is(cause, context.Canceled) +} + +// IsServerShutdown reports whether cause is a request cut by server teardown. +func IsServerShutdown(cause error) bool { + return errors.Is(cause, ErrServerShuttingDown) +} + // cancelCauseKey is the gin context key where RequestTimeout snapshots the // cancel cause before defer-cancel runs. const cancelCauseKey = "middleware.cancelCause" diff --git a/packages/shared/pkg/middleware/timeout_test.go b/packages/shared/pkg/middleware/timeout_test.go index 59cfcc041a..2c5919cff5 100644 --- a/packages/shared/pkg/middleware/timeout_test.go +++ b/packages/shared/pkg/middleware/timeout_test.go @@ -1,6 +1,9 @@ package middleware import ( + "context" + "errors" + "fmt" "net/http" "net/http/httptest" "testing" @@ -104,3 +107,64 @@ func TestRequestTimeout_TimeoutContextVisibleToOuterMiddleware(t *testing.T) { require.ErrorIs(t, outerCause, ErrRequestTimeout, "outer middleware should see ErrRequestTimeout as the cause when the timeout fires") } + +func TestClassifyCancelCause(t *testing.T) { + t.Parallel() + + for name, tt := range map[string]struct { + cause error + wantClient bool + wantServerShutdn bool + }{ + "nil": {cause: nil, wantClient: false, wantServerShutdn: false}, + "client disconnect": {cause: context.Canceled, wantClient: true, wantServerShutdn: false}, + "wrapped client": {cause: fmt.Errorf("read: %w", context.Canceled), wantClient: true, wantServerShutdn: false}, + "request timeout": {cause: ErrRequestTimeout, wantClient: false, wantServerShutdn: false}, + "server shutdown": {cause: ErrServerShuttingDown, wantClient: false, wantServerShutdn: true}, + "wrapped shutdown": {cause: fmt.Errorf("ctx: %w", ErrServerShuttingDown), wantClient: false, wantServerShutdn: true}, + "deadline exceeded": {cause: context.DeadlineExceeded, wantClient: false, wantServerShutdn: false}, + "unrelated error": {cause: errors.New("boom"), wantClient: false, wantServerShutdn: false}, + } { + t.Run(name, func(t *testing.T) { + t.Parallel() + + assert.Equal(t, tt.wantClient, IsClientDisconnect(tt.cause), "IsClientDisconnect") + assert.Equal(t, tt.wantServerShutdn, IsServerShutdown(tt.cause), "IsServerShutdown") + }) + } +} + +// TestServerShutdownCausePropagatesToOuterMiddleware proves the end-to-end +// wiring: a request whose parent context is cancelled with +// ErrServerShuttingDown (as the server does on teardown via BaseContext) +// surfaces that cause to an outer middleware through the RequestTimeout +// wrapper, so it is classified as a server shutdown rather than a client +// disconnect. See issue #3685. +func TestServerShutdownCausePropagatesToOuterMiddleware(t *testing.T) { + t.Parallel() + + baseCtx, cancelBase := context.WithCancelCause(t.Context()) + + var outerCause error + outerMiddleware := func(c *gin.Context) { + c.Next() + outerCause = CancelCause(c) + } + + r := gin.New() + r.Use(outerMiddleware) + r.Use(RequestTimeout(5 * time.Second)) + r.GET("/slow", func(c *gin.Context) { + // Server tears down while this request is in flight. + cancelBase(ErrServerShuttingDown) + <-c.Request.Context().Done() + }) + + w := httptest.NewRecorder() + req, _ := http.NewRequestWithContext(baseCtx, http.MethodGet, "/slow", nil) + r.ServeHTTP(w, req) + + require.ErrorIs(t, outerCause, ErrServerShuttingDown) + assert.True(t, IsServerShutdown(outerCause), "a teardown-cut request must classify as server shutdown") + assert.False(t, IsClientDisconnect(outerCause), "a teardown-cut request must not classify as a client disconnect") +}