registry/internal/api/router/router_test.go
Radoslav Dimitrov 4e147072f0
metrics: stop counting client-cancelled requests as server errors (#1255)
## Summary

- Remap recorded status to `499` (NGINX-style "client closed") when
`ctx.Context().Err()` is `context.Canceled` after the handler returns
- Skip the `http_errors_total` increment for `499`s so the availability
metric reflects server-visible errors only

## Why

Under scraper-driven load, clients with short timeouts paginate
`/v0.1/servers`, give up while PG is busy, and close the TCP connection.
The handler's DB iteration returns `context canceled`, the handler
converts that to `huma.Error500InternalServerError`, and tries to write
a response to the now-closed socket. NGINX records `499` (client closed)
and never delivers anything to the client — but the registry's
middleware records `status_code=500` and bumps
`mcp_registry_http_errors_total`.

That's what's been firing the `Availability dropped below 95%` alert
during the daily 17:00 UTC bursts. Recent prod numbers from one pod
(~19h uptime):

```
mcp_registry_http_errors_total{path="/v0.1/servers", status_code="500"} 7396
mcp_registry_http_errors_total{path="/v0.1/servers/{serverName}/versions", status_code="500"} 283
mcp_registry_http_errors_total{path="/v0/servers", status_code="500"} 352
```

…against zero 5xx in NGINX ingress logs over the same window. The alert
was correct *given the data it had*; the data was misclassifying client
cancellations as server errors.

## What this does

In `internal/api/router/router.go` (the metric middleware): after
`next(ctx)`, check `ctx.Context().Err()`. If it's `context.Canceled`,
override `statusCode` to `499` and skip the error counter. Requests
counter and duration histogram still record so the cancellation rate
stays visible.

`context.DeadlineExceeded` is intentionally **not** remapped — that
would indicate a server-side timeout if we ever add per-request
deadlines, and should still count as a server error.

## What this does *not* do

- Doesn't reduce the underlying load (ServiceNow + notion catalog
scrapers driving the daily peak — separate work, see the `updated_since`
outreach we're doing).
- Doesn't change handler behaviour — handlers still call
`huma.Error500…` on `context.Canceled`. We could short-circuit earlier
(return without writing) to save the work, but that's a bigger refactor
and the metric fix unblocks the alert immediately.

## Companion change (no code, just a Grafana annotation tweak)

The `Availability dropped below 95%` alert (UID `bexrc60etvhmoa`)
currently has the annotation:

> No. of 5xx are increased from acceptable limit i.e. 5% of total
throughput

The query is on `mcp_registry_http_errors_total`, not 5xx specifically.
After this change the count is meaningful again, but the wording is
still misleading. Suggest updating to:

> Internal error rate exceeded 5% of total throughput

(no PromQL change required.)

## Test plan

- [x] `go test ./internal/api/router/...` — new test passes
- [x] `golangci-lint run ./internal/...` — clean
- [ ] After merge, watch a daily 17:00 UTC burst —
`mcp_registry_http_errors_total{status_code="500",
path="/v0.1/servers"}` should stay flat while
`mcp_registry_http_requests_total{status_code="499",
path="/v0.1/servers"}` grows. Availability alert should not fire on
cancellation-only bursts.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-authored-by: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-05-05 05:58:05 -04:00

119 lines
4.1 KiB
Go

package router_test
import (
"context"
"errors"
"net/http"
"net/http/httptest"
"strings"
"testing"
"github.com/danielgtaylor/huma/v2"
"github.com/danielgtaylor/huma/v2/adapters/humago"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"github.com/modelcontextprotocol/registry/internal/api/router"
"github.com/modelcontextprotocol/registry/internal/telemetry"
)
// TestMetricMiddleware_ClientCancelledNotCountedAsError verifies that a request
// the client gave up on (request-context Canceled) is recorded as 499 in
// http_requests_total and is NOT incremented in http_errors_total — even when
// the handler returned huma.Error500InternalServerError because its DB call
// surfaced context.Canceled.
//
// Regression test for the case where a ServiceNow-style scraper burst
// generated thousands of internal 500s for cancelled requests, tripping the
// "Availability dropped below 95%" alert despite zero 5xx reaching clients.
func TestMetricMiddleware_ClientCancelledNotCountedAsError(t *testing.T) {
shutdown, metrics, err := telemetry.InitMetrics("test")
require.NoError(t, err)
defer func() { _ = shutdown(context.Background()) }()
mux := http.NewServeMux()
api := humago.New(mux, huma.DefaultConfig("Test API", "1.0.0"))
api.UseMiddleware(router.MetricTelemetryMiddleware(metrics))
// Handler that simulates: DB returns context.Canceled because the client
// disconnected, handler converts to huma 500.
huma.Register(api, huma.Operation{
OperationID: "cancelled-list",
Method: http.MethodGet,
Path: "/v0/servers",
}, func(_ context.Context, _ *struct{}) (*struct{}, error) {
return nil, huma.Error500InternalServerError("Failed to get registry list",
errors.New("error iterating rows: context canceled"))
})
mux.Handle("/metrics", metrics.PrometheusHandler())
cancelledCtx, cancel := context.WithCancel(context.Background())
cancel()
req := httptest.NewRequest(http.MethodGet, "/v0/servers", nil).WithContext(cancelledCtx)
rec := httptest.NewRecorder()
mux.ServeHTTP(rec, req)
scrapeReq := httptest.NewRequest(http.MethodGet, "/metrics", nil)
scrapeRec := httptest.NewRecorder()
mux.ServeHTTP(scrapeRec, scrapeReq)
assert.Equal(t, http.StatusOK, scrapeRec.Code)
body := scrapeRec.Body.String()
// The request is recorded — but as 499, not 500.
assert.True(t,
containsMetric(body, `mcp_registry_http_requests_total`, `status_code="499"`, `path="/v0/servers"`),
"expected requests_total to record status_code=499 for the cancelled request; got:\n%s",
filterMetricLines(body, "mcp_registry_http_requests_total"),
)
assert.False(t,
containsMetric(body, `mcp_registry_http_requests_total`, `status_code="500"`, `path="/v0/servers"`),
"did not expect requests_total to record status_code=500 for a client-cancelled request; got:\n%s",
filterMetricLines(body, "mcp_registry_http_requests_total"),
)
// The error counter is NOT bumped for 499s — that is the point of this fix.
assert.False(t,
containsMetric(body, `mcp_registry_http_errors_total`, `status_code="499"`),
"errors_total must not be incremented for client-cancelled requests; got:\n%s",
filterMetricLines(body, "mcp_registry_http_errors_total"),
)
assert.False(t,
containsMetric(body, `mcp_registry_http_errors_total`, `status_code="500"`, `path="/v0/servers"`),
"errors_total must not record a 500 for a request the client already gave up on; got:\n%s",
filterMetricLines(body, "mcp_registry_http_errors_total"),
)
}
// containsMetric returns true iff some line in body starts with `metric{...}`
// and that label set contains every requested label fragment.
func containsMetric(body, metric string, labels ...string) bool {
for _, line := range strings.Split(body, "\n") {
if !strings.HasPrefix(line, metric+"{") {
continue
}
ok := true
for _, l := range labels {
if !strings.Contains(line, l) {
ok = false
break
}
}
if ok {
return true
}
}
return false
}
func filterMetricLines(body, metric string) string {
var lines []string
for _, line := range strings.Split(body, "\n") {
if strings.HasPrefix(line, metric) {
lines = append(lines, line)
}
}
return strings.Join(lines, "\n")
}