feat(upstream): log the reason an upstream rejected a request #86

Merged

coilysiren merged 1 commit from fix/reconnect-after-close into main

2026-08-19 04:44:20 +00:00

coilyco-ops commented

2026-08-19 04:43:29 +00:00

Member

Refs #85. This diagnoses, it does not fix. I could not fix #85 and I would rather say that than ship a guess.

What this adds

The Go SDK surfaces an HTTP rejection as its status line, so a 400 reaches mcp-beaver as the bare string Bad Request and the server's own explanation is discarded unread. #85's whole point is that this one string has now misdirected three investigations.

A round tripper reads the body on any 4xx or 5xx and logs it beside the status, the session id and the negotiated protocol version, then restores the body so the caller still gets a complete response. Bounded at 512 bytes: a reason is a sentence, anything longer is a page.

The next occurrence will name its own cause. Concretely, the SDK's own server has at least three distinct 400s that all reach us as the same two words:

Bad Request: Unsupported protocol version (supported versions: ...)
Bad Request: DELETE requires an Mcp-Session-Id header
Bad Request: GET requires an Mcp-Session-Id header

Which of those the upstream is sending is currently unknowable from our side, and it is the whole question.

A hypothesis I built, tested, and disproved

Recording it so nobody rebuilds it.

I reasoned that reconnect closes the stale session before dialing, that Close sends DELETE, and that an upstream tearing its transport down on DELETE would then refuse the next initialize - which fits #85 exactly, since the initial dial always succeeds and only reconnects fail. I wrote the reorder and a fixture whose upstream bricks after a DELETE.

The test passed without the change, which is the only reason I checked the premise. The SDK does not send the DELETE in this case at all:

func (c *streamableClientConn) Close() error {
	c.closeOnce.Do(func() {
		if errors.Is(c.failure(), ErrSessionMissing) {
			// If the session is missing, no need to delete it.
		}

A reconnect happens precisely because the upstream forgot the session, so ErrSessionMissing is set and no DELETE is ever sent. The reorder would have been a no-op shipped as a fix, and the vacuous test would have locked it in. Both are dropped from this PR.

What is still true and still unexplained

The initial dial succeeds on every pod, every time. Pods reach Ready and snapshot their baseline.
A reconnect fails at notifications/initialized, the first request after initialize, which is also the first request carrying MCP-Protocol-Version.
It is not pod state. I drove a browser call through sirens-deep's pod, in a different namespace, and got the identical error to sirens-dowel's.
It is not resource pressure. The browser sits at 462Mi of a 2Gi limit with zero restarts and no OOM.

The protocol-version header being the discriminator between "handshake that works" and "handshake that fails" is where I would look next, and this PR is what makes that readable rather than guessable.

Tests

Two. One asserts the server's reason, the session id and the status all reach the log and that the caller still reads a complete body, so this stays an observer. The other asserts a healthy response is untouched and logs nothing.

go test ./... and pre-commit run --all-files green.

Refs #85. **This diagnoses, it does not fix.** I could not fix #85 and I would rather say that than ship a guess. ## What this adds The Go SDK surfaces an HTTP rejection as its status line, so a 400 reaches mcp-beaver as the bare string `Bad Request` and the server's own explanation is discarded unread. #85's whole point is that this one string has now misdirected three investigations. A round tripper reads the body on any 4xx or 5xx and logs it beside the status, the session id and the negotiated protocol version, then restores the body so the caller still gets a complete response. Bounded at 512 bytes: a reason is a sentence, anything longer is a page. The next occurrence will name its own cause. Concretely, the SDK's own server has at least three distinct 400s that all reach us as the same two words: ``` Bad Request: Unsupported protocol version (supported versions: ...) Bad Request: DELETE requires an Mcp-Session-Id header Bad Request: GET requires an Mcp-Session-Id header ``` Which of those the upstream is sending is currently unknowable from our side, and it is the whole question. ## A hypothesis I built, tested, and disproved Recording it so nobody rebuilds it. I reasoned that `reconnect` closes the stale session **before** dialing, that `Close` sends `DELETE`, and that an upstream tearing its transport down on DELETE would then refuse the next `initialize` - which fits #85 exactly, since the initial dial always succeeds and only reconnects fail. I wrote the reorder and a fixture whose upstream bricks after a DELETE. **The test passed without the change**, which is the only reason I checked the premise. The SDK does not send the DELETE in this case at all: ```go func (c *streamableClientConn) Close() error { c.closeOnce.Do(func() { if errors.Is(c.failure(), ErrSessionMissing) { // If the session is missing, no need to delete it. } ``` A reconnect happens precisely because the upstream forgot the session, so `ErrSessionMissing` is set and no DELETE is ever sent. The reorder would have been a no-op shipped as a fix, and the vacuous test would have locked it in. Both are dropped from this PR. ## What is still true and still unexplained * The initial dial succeeds on every pod, every time. Pods reach Ready and snapshot their baseline. * A reconnect fails at `notifications/initialized`, the first request after `initialize`, which is also the first request carrying `MCP-Protocol-Version`. * It is not pod state. I drove a browser call through `sirens-deep`'s pod, in a different namespace, and got the identical error to `sirens-dowel`'s. * It is not resource pressure. The browser sits at 462Mi of a 2Gi limit with zero restarts and no OOM. The protocol-version header being the discriminator between "handshake that works" and "handshake that fails" is where I would look next, and this PR is what makes that readable rather than guessable. ## Tests Two. One asserts the server's reason, the session id and the status all reach the log **and** that the caller still reads a complete body, so this stays an observer. The other asserts a healthy response is untouched and logs nothing. `go test ./...` and `pre-commit run --all-files` green.

coilyco-ops added 1 commit

2026-08-19 04:43:29 +00:00

feat(upstream): log the reason an upstream rejected a request

ci / gate (push) Successful in 33s

Details

ci / publish (push) Has been skipped

Details

ci / gate (pull_request) Successful in 37s

Details

ci / publish (pull_request) Has been skipped

Details

4e8e1fe77f

The SDK surfaces a rejection as its status line, so mcp-beaver reports
"Bad Request" and the server's explanation is read by nobody. #85 records
three investigations misdirected by that one omission, mine included: the
400 has a body naming which check failed, and it has never been read.

A round tripper reads it on any 4xx or 5xx and logs it beside the status,
the session id and the negotiated protocol version, then puts the body
back so the caller still receives a complete response. Bounded at 512
bytes, because a reason is a sentence and anything longer is a page.

This diagnoses rather than fixes. I do not know why a reconnect is
rejected when the identical handshake succeeds at startup, and the next
occurrence should say so itself instead of costing a fourth investigation.

Co-authored-by: Kai Siren <coilysiren@gmail.com>
Co-authored-by: Claude <noreply@anthropic.com>

coilyco-ops requested review from coilysiren

2026-08-19 04:43:29 +00:00