fix(graphql): log JSON encode failure in respondWithErrors (#4256)

[NitinKumar004]

Description:

Fixes #4256.

graphQLManager.respondWithErrors discarded the error from json.NewEncoder(w).Encode(...). Logging it makes the error path consistent with the success path in the same file, which already logs its encode error.

This is defensive rather than a fix for an observed failure. The body is a literal map[string]any holding one of three constant strings, so marshalling can't fail, and net/http buffers a body this small (≤ 65 bytes), so a client disconnect doesn't surface as a write error inside the handler either. The log only fires if the ResponseWriter itself returns an error from Write.

Changes:

• respondWithErrors now checks the encode error and logs it via the container logger: error encoding GraphQL error response: <err>. This mirrors the existing success-path log in the same file (error encoding GraphQL response: %v, Error level).
• The status line has already been written by the time the encode runs, so logging is all this function can do. (Separately, the panic-recovery path can reach it after a 200 has already been sent. That is pre-existing and out of scope here; happy to open an issue for it.)
• Added the missing blank line before GetHandler.

Tests (pkg/gofr/graphql_test.go):

• Test_respondWithErrors: the three real error responses (500 / 415 / 400) produce the right status, Content-Type, and {"errors":[{"message": ...}]} body, and nothing is logged.
• Test_respondWithErrors_WriteFailureIsLogged: with a synthetic ResponseWriter whose Write fails, the error is logged (this test fails on the old code). It exercises the logging path; it isn't a reproduction of a real disconnect.
• TestGraphQL_RequestErrors: covers the previously untested 415 (wrong Content-Type) and 400 (invalid JSON body) paths end-to-end through GetHandler(), so it stays compatible with perf(deps): let a build omit the datasource drivers and GraphQL engine it does not use #4167's graphQLRunner interface.

Breaking Changes (if applicable):

None.

Additional Information:

No new dependencies. Out of scope, but the same _ = json.NewEncoder(w).Encode(...) pattern exists in pkg/gofr/http/middleware/logger.go (panic recovery) and pkg/gofr/ai/mcp/jsonrpc.go (writeJSON); happy to follow up if desired.

Checklist:

• I have formatted my code using goimport and golangci-lint.
• All new code is covered by unit tests.
• This PR does not decrease the overall code coverage.
• I have reviewed the code comments and documentation for clarity.

[aryanmehrotra]

The change itself is right — Errorf not Error, matching the pattern 50 lines above it, and it takes respondWithErrors from 0% to 100% coverage with handleGraphQLRequest going 79.3% → 96.6%. The mutation test is clean: reverting to _ = json.NewEncoder(w).Encode(...) fails the new test.

Worth calling out that you used Errorf without being prompted. I captured both against the production JSON logger:

Errorf → {"level":"ERROR","message":"error encoding GraphQL error response: write failed"}
Error  → {"level":"ERROR","message":{}}

The second is the trap — the logger JSON-marshals a bare error value and errors.errorString has no exported fields, so the text is lost. You're on the right side of it.

Requesting changes for the merge collision, and one correction to the description.

1. This will not compile once #4167 lands

#4167 (perf/optional-datasources-graphql) makes GraphQL optional behind gofr_nographql and changes App.graphqlManager from *graphQLManager to a graphQLRunner interface whose methods are RegisterQuery, RegisterMutation, buildSchema, GetHandler — Handle is not on it. That's why it rewrites the eight existing app.graphqlManager.Handle(...) call sites to gqlManager(t, app).Handle(...).

This PR's new TestGraphQL_RequestErrors adds a ninth at graphql_test.go:535. I counted: nine call sites here, eight converted there.

There's also a trivial text conflict at the top of graphql_test.go (that PR's gqlManager helper vs this PR's errWriter) — resolution is "keep both". graphql.go auto-merges cleanly.

Whichever lands second needs the one-line change; flagging so it isn't a surprise. Nothing to do now beyond being aware.

2. The description claims a failure mode this can't catch

The body says the encode can fail "for example, the client disconnected". I don't think that case is reachable here. json.Encoder.Encode marshals fully into its own buffer and issues a single Write (encoding/json/stream.go:225-233), and net/http hands the handler a 2048-byte bufio.Writer (net/http/server.go:341, allocated :1071) that isn't flushed until finishRequest (:1671). The largest of the three bodies here is 65 bytes, so the write never reaches the socket inside the handler.

I tested it with a client that RSTs the connection before the handler writes:

65-byte body    Encode() err = <nil>
>2048-byte body Encode() err = write tcp ...: write: broken pipe

The marshal half is closed too — the value is a literal map[string]any holding one of three compile-time strings, so there's no channel, func, cycle or float that could fail.

I'm happy with the change as hygiene and for consistency with line 464. Could you just reword the description so it doesn't claim the disconnect case? And a comment on errWriter saying it's a synthetic failure rather than a reproduction of a real disconnect would stop the next reader concluding the production path is covered.

3. Please drop the AI-attribution footer

The PR body carries a 🤖 Generated with [Claude Code] line. This repo's convention is that merged history attributes only the human author.

Two things for context, not for this PR

• GoFr's house pattern is the other way round. pkg/gofr/http/responder.go:134-146 encodes into a buffer first and only commits the status once the encode succeeded, so an encode error produces a clean 500 instead of a truncated 200. Here that costs nothing (marshal can't fail on a literal), so I wouldn't change it. But if you do the follow-up you offered for middleware/logger.go:345 and ai/mcp/jsonrpc.go:71, responder.go is the shape worth copying rather than this one.
• The panic path already sends a broken response, and this PR doesn't change that. respondWithErrors is also reached from the recover at graphql.go:401-406, by which point handleGraphQLRequest may have sent a 200 (:462) and a full body (:464), with its deferred metrics/span block (:434-445) running after. The WriteHeader(500) is then dropped — silently, because StatusResponseWriter.WriteHeader short-circuits at middleware/logger.go:41-43 and never reaches net/http's "superfluous WriteHeader" warning — and the client gets 200 with two concatenated JSON documents. Pre-existing and out of scope, but the description's "status and headers are already committed, so logging is the only meaningful action" reads as if that case were fine. Worth a separate issue?

No leaks — the three messages are compile-time constants, and the only variable content is the transport error text, which is a client IP:port the access log already records.

Verified: gofmt clean, go vet clean, all 16 CI checks green, golangci-lint identical count and breakdown to origin/development (0 introduced). The two local failures under -race and -count=5 (websocket.go:47 race, port-2121 probe) reproduce on development.

[NitinKumar004]

Thanks for the thorough review, especially the bufio analysis. I hadn't traced the write that far.

Pushed 60988e1:

1. perf(deps): let a build omit the datasource drivers and GraphQL engine it does not use #4167 collision: I didn't want this PR to add a ninth call site that breaks, so TestGraphQL_RequestErrors now goes through app.graphqlManager.GetHandler().ServeHTTP(...) instead of Handle. GetHandler is on the graphQLRunner interface, so it compiles in either merge order. I applied this diff on top of perf(deps): let a build omit the datasource drivers and GraphQL engine it does not use #4167 locally to check: graphql.go merges cleanly and graphql_test.go only has the expected "keep both" conflict at the top. It builds and passes with and without gofr_nographql. The other eight call sites are left to perf(deps): let a build omit the datasource drivers and GraphQL engine it does not use #4167.
2. Description: reworded. It no longer claims the disconnect case, and it says the change is defensive and for consistency with the success-path log. I also rewrote the errWriter comment so it's clearly a synthetic write failure used to exercise the log path, not a reproduction of a real disconnect.
3. Footer: removed.

Noted on responder.go's buffer-first shape. I'll use that for the middleware/logger.go / mcp/jsonrpc.go follow-up rather than this pattern. And yes, I'll open a separate issue for the panic-path double response (200 plus a second JSON document, with the 500 silently dropped). I also softened the "logging is the only meaningful action" line in the description so it doesn't read as if that case were fine.

[aryanmehrotra]

All three addressed, and I verified each by execution rather than by reading.

The #4167 collision is resolved and the merged tree is green. I test-merged this into perf/optional-datasources-graphql (2139269c3) and ran it both ways:

check	result
go build ./... merged	PASS
go build -tags gofr_nographql ./...	PASS
go test ./pkg/gofr/ -count=1 merged	ok 7.069s
go test -tags gofr_nographql ./pkg/gofr/ -count=1	ok 8.498s
graphql tests on the merged tree	14 tests / 20 subtests, all pass

Zero app.graphqlManager.Handle( remain; routing through GetHandler().ServeHTTP puts it on the graphQLRunner interface, which is exactly right. GetHandler() is http.HandlerFunc(m.Handle) (graphql.go:527-529), so the executed path is identical — and GetHandler now reaches 100% itself. Coverage held: respondWithErrors 0% → 100%, handleGraphQLRequest 79.3% → 96.6%, package 88.7% → 89.1%.

One trivial hunk still conflicts — graphql_test.go:24-55, where both sides insert a top-level block right after the imports (errWriteFailed/errWriter here, gqlManager() there). Resolution is "keep both", in either order; that's what produced the green results above. Whichever of the two lands second owns it, and I'll flag it on #4167 too so neither of you is surprised.

The fix is pinned. Reverting respondWithErrors to _ = json.NewEncoder(w).Encode(...) with the tests untouched:

--- FAIL: Test_respondWithErrors_WriteFailureIsLogged
    graphql_test.go:502: "" does not contain "error encoding GraphQL error response"
    graphql_test.go:503: "" does not contain "write failed"

Errorf confirmed against the production logger, not the mock:

Errorf → {"level":"ERROR","message":"error encoding GraphQL error response: write failed","gofrVersion":"dev"}
Error  → {"level":"ERROR","message":{},"gofrVersion":"dev"}

The body is accurate now. You retracted the disconnect claim rather than softening it, which is what I was hoping for — and the "≤ 65 bytes" figure checks out exactly: {"errors":[{"message":"Content-Type must be application/json"}]}\n is 65 bytes, the largest of the three. The errWriter comment says plainly that it's synthetic and not a disconnect reproduction, with the reason. Attribution footer gone from the body and from both commit messages.

Two notes, neither blocking:

• Your first commit message (8b9122d32) still carries the "e.g. client disconnected" wording that the body now retracts. This repo squash-merges — I checked the last twelve merges into development and every one is a single-parent commit titled with the PR title — so the PR body is what lands in history and the stale message never reaches it. Flagging only so you know it isn't being overlooked.
• Please do open the follow-up you offered. pkg/gofr/http/middleware/logger.go:345 and pkg/gofr/ai/mcp/jsonrpc.go:71 both still carry the discarded-encode pattern. If you take it up, pkg/gofr/http/responder.go:134-146 is the shape worth copying — buffer first, commit the status only once the encode succeeded — rather than this one, which is right here only because the value is a literal that can't fail to marshal.

Gates: gofmt clean, go vet clean, golangci-lint identical to development (0 introduced — the only delta is the pre-existing swagger.go:33 goconst counter going 14 → 15). The -race and -count=5 failures reproduce byte-identically on development (the websocket.go:47 ↔ handler.go:190 race and the port-2121 isPortAvailable probe). The new tests are race-clean in isolation.

[NitinKumar004]

Thanks for the approval, and for checking the #4167 merge both ways.

Filed the follow-up as #4320: the discarded encode errors in middleware/logger.go:345 (panic recovery) and ai/mcp/jsonrpc.go:71. It suggests http/responder.go's buffer-first shape rather than this one, as you said.