Skip to content

/v0/servers logs benign client cancellations as "list servers failed" and triggers "superfluous response.WriteHeader" warnings #1323

@tadasant

Description

@tadasant

🤖 This issue was generated by Claude Code.

Thanks to @pree-dew (Pree) for reporting these log lines at the last Registry Working Group meeting. 🙏

Summary

When a client disconnects mid-request on GET /v0/servers, the list handler does not detect the cancellation. It (a) logs the resulting context.Canceled at default level as list servers failed: ..., and (b) returns huma.Error500InternalServerError, which makes huma attempt to write a status to an already-committed/closed response — producing a superfluous response.WriteHeader call warning. Both are benign-but-noisy: no real client is affected, because the client has already gone away.

Observed log lines (production)

2026/05/28 20:28:26 list servers failed: error iterating rows: context canceled
... superfluous response.WriteHeader call from github.com/danielgtaylor/huma/v2/adapters/humago.(*goContext).SetStatus (humago.go:110)

Root cause

internal/api/handlers/v0/servers.go (~line 135) logs and 500s on every error from the service, with no special-casing for client cancellation:

servers, nextCursor, err := registry.ListServers(ctx, filter, input.Cursor, input.Limit)
if err != nil {
    log.Printf("list servers failed: %v", err)
    return nil, huma.Error500InternalServerError("Failed to get registry list")
}

The error string originates from internal/database/postgres.go (~line 262), fmt.Errorf("error iterating rows: %w", err), where rows.Err() returns context.Canceled when the client disconnects during row streaming. Returning a huma 5xx here then drives humago's SetStatus (adapters/humago/humago.go:110, which calls w.WriteHeader unguarded) to write a status onto a response whose header is already committed → the superfluous response.WriteHeader call warning.

So the two log lines are two symptoms of one root cause: the list handler does not short-circuit on client cancellation.

Affected files

  • internal/api/handlers/v0/servers.go (≈ line 135) — unconditional error log + 500
  • internal/database/postgres.go (≈ line 262) — error origin (the same error iterating rows pattern also appears at ≈ lines 479 and 722 and shares the exposure)
  • internal/service/registry_service.go (≈ line 55) — pass-through

Relationship to existing work

  • metrics: stop counting client-cancelled requests as server errors #1255 (merged) fixed only the metrics side — it remaps cancelled 500499 in internal/api/router/router.go and skips http_errors_total. Its description explicitly notes handlers "still call huma.Error500… on context.Canceled" and "tried to write a response to a closed socket", i.e. the handler-side logging and double-write were deliberately left out of scope.
  • API latency: /v0/servers reads consistently take 20–25s #1252 (open) tracks the underlying /v0/servers latency that causes clients to time out and cancel in the first place. This issue is about the noisy logging/response behavior and is independent of the latency fix.

A regression test already associates this exact error string with cancellation: internal/api/router/router_test.go's TestMetricMiddleware_ClientCancelledNotCountedAsError simulates it with errors.New("error iterating rows: context canceled").

Suggested fix direction

Detect cancellation in the list handler before logging an error or returning a 5xx, e.g.:

if err != nil {
    if errors.Is(err, context.Canceled) || ctx.Err() != nil {
        // client went away — nothing to return; skip the noisy error log and 5xx
        return nil, huma.Error499ClientClosedRequest(...) // or return the context error without error-level logging
    }
    log.Printf("list servers failed: %v", err)
    return nil, huma.Error500InternalServerError("Failed to get registry list")
}

Returning early (without invoking the error-response writer) also prevents the second WriteHeader. Consider applying the same guard to the other handlers that call streaming db.* methods, and/or downgrading cancellation to a debug-level log. A small regression test mirroring the existing TestMetricMiddleware_ClientCancelledNotCountedAsError could assert that no error-level log / no 5xx is produced on cancellation.

Reproduction

make dev-compose, then curl --max-time 0.05 http://localhost:8080/v0/servers (or start the request and abort it). Both log lines appear on the server.

Severity

Low — log noise only; no client-visible incorrect behavior. Worth fixing to keep stderr/alerting signal clean and to avoid masking genuine double-write bugs.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions