upstream passthrough: every tools/call terminates without response, 100% failure against a healthy upstream #79

Closed
opened 2026-08-17 03:19:57 +00:00 by coilyco-ops · 2 comments
Member

What

In runtime.mode: upstream, every tools/call fails instantly. Probed live against sirens-deep-playwright-mcp in the sirens-deep namespace:

== initialize  sirens-deep-playwright-mcp.sirens-deep:8080
   server: {"name": "playwright", "version": "0.1.0"}

== tools/list
   8 advertised: browser_click, browser_console_messages, browser_navigate,
   browser_network_requests, browser_snapshot, browser_take_screenshot,
   browser_type, browser_wait_for

== tools/call  browser_navigate  {"url":"https://example.com"}
{
  "jsonrpc": "2.0", "id": 3,
  "result": {
    "content": [{"type": "text",
                 "text": "calling \"tools/call\": request terminated without response"}],
    "isError": true
  }
}

The shape says only tools/call is proxied

initialize returned {"name": "playwright", "version": "0.1.0"}. That is the upstream.name value from the deploy values file with a placeholder version, not the upstream Microsoft playwright-mcp's real serverInfo. tools/list returned exactly the eight names in the upstream.tools allowlist.

Both are answered locally. tools/call is the only operation that actually crosses to the upstream, and it is the only one that fails. That is consistent with the passthrough never having completed a successful upstream exchange.

Evidence from production, before the probe

Over 24h on ser8, sirens-deep's playwright MCP recorded 0 successes and a constant error across three unrelated tools:

  • browser_navigate - failed, result_bytes 72
  • browser_snapshot - failed, result_bytes 72
  • browser_console_messages - failed, result_bytes 72

p95 duration 16.8ms. An identical-size error across tools with completely different work is a single rejection path before dispatch, and the probe confirms it is the upstream hop.

Ruled out

  • Not schema. browser_navigate takes one required string, url.
  • Not the allowlist. All 8 allowed tools match the 8 advertised, and the probe called one of them by name.
  • Not transport into mcp-beaver. 16 mcp.session POST spans to this service, zero errors.
  • Not the upstream image. Same digest (playwright-mcp:upstream-dd643326...) runs standalone in the playwright-mcp namespace, where a live browser_tabs call answers correctly.
  • Not pod health. Both containers ready: true, restart_count: 0.
  • Not a timeout. 16ms against upstream.connectTimeout: 2m.

Leading hypothesis

request terminated without response reads as the upstream connection closing before a JSON-RPC reply. The upstream is streamable HTTP and requires an initialize handshake plus an Mcp-Session-Id on subsequent requests. If the passthrough POSTs tools/call without having established a session with the upstream, the server terminates the request exactly this way: instantly, identically, for every tool.

That fits every observation, including why the locally-answered operations look healthy while the proxied one never works.

Not confirmed. The decisive test is a direct probe of the sidecar on 127.0.0.1:8931 with a correct handshake. If that succeeds where the passthrough fails, the handshake is the gap.

Reproducing

coilyco-bridge/deploy PR #594 adds probe-mcp-beaver, which produced the output above:

ward exec probe-mcp-beaver
ward exec probe-mcp-beaver -- --list   # inert, calls nothing

Impact

Sirens Deep has had a completely non-functional browser for as long as this has been deployed, while advertising eight browser tools to the model. Every call the model makes to it is a wasted turn. It went unnoticed because failed tool calls set no span error status (coilyco-gaming/sirens-echo#873) and mcp-beaver logs nothing (#78).

Worth checking whether sirens-echo-playwright-mcp, which runs the identical configuration, is equally dead.

## What In `runtime.mode: upstream`, every `tools/call` fails instantly. Probed live against `sirens-deep-playwright-mcp` in the `sirens-deep` namespace: ``` == initialize sirens-deep-playwright-mcp.sirens-deep:8080 server: {"name": "playwright", "version": "0.1.0"} == tools/list 8 advertised: browser_click, browser_console_messages, browser_navigate, browser_network_requests, browser_snapshot, browser_take_screenshot, browser_type, browser_wait_for == tools/call browser_navigate {"url":"https://example.com"} { "jsonrpc": "2.0", "id": 3, "result": { "content": [{"type": "text", "text": "calling \"tools/call\": request terminated without response"}], "isError": true } } ``` ## The shape says only tools/call is proxied `initialize` returned `{"name": "playwright", "version": "0.1.0"}`. That is the `upstream.name` value from the deploy values file with a placeholder version, not the upstream Microsoft playwright-mcp's real serverInfo. `tools/list` returned exactly the eight names in the `upstream.tools` allowlist. Both are answered locally. `tools/call` is the only operation that actually crosses to the upstream, and it is the only one that fails. That is consistent with the passthrough never having completed a successful upstream exchange. ## Evidence from production, before the probe Over 24h on ser8, sirens-deep's playwright MCP recorded 0 successes and a constant error across three unrelated tools: * `browser_navigate` - failed, `result_bytes` 72 * `browser_snapshot` - failed, `result_bytes` 72 * `browser_console_messages` - failed, `result_bytes` 72 p95 duration 16.8ms. An identical-size error across tools with completely different work is a single rejection path before dispatch, and the probe confirms it is the upstream hop. ## Ruled out * **Not schema.** `browser_navigate` takes one required string, `url`. * **Not the allowlist.** All 8 allowed tools match the 8 advertised, and the probe called one of them by name. * **Not transport into mcp-beaver.** 16 `mcp.session POST` spans to this service, zero errors. * **Not the upstream image.** Same digest (`playwright-mcp:upstream-dd643326...`) runs standalone in the `playwright-mcp` namespace, where a live `browser_tabs` call answers correctly. * **Not pod health.** Both containers `ready: true`, `restart_count: 0`. * **Not a timeout.** 16ms against `upstream.connectTimeout: 2m`. ## Leading hypothesis `request terminated without response` reads as the upstream connection closing before a JSON-RPC reply. The upstream is streamable HTTP and requires an `initialize` handshake plus an `Mcp-Session-Id` on subsequent requests. If the passthrough POSTs `tools/call` without having established a session with the upstream, the server terminates the request exactly this way: instantly, identically, for every tool. That fits every observation, including why the locally-answered operations look healthy while the proxied one never works. Not confirmed. The decisive test is a direct probe of the sidecar on `127.0.0.1:8931` with a correct handshake. If that succeeds where the passthrough fails, the handshake is the gap. ## Reproducing `coilyco-bridge/deploy` PR #594 adds `probe-mcp-beaver`, which produced the output above: ```sh ward exec probe-mcp-beaver ward exec probe-mcp-beaver -- --list # inert, calls nothing ``` ## Impact Sirens Deep has had a completely non-functional browser for as long as this has been deployed, while advertising eight browser tools to the model. Every call the model makes to it is a wasted turn. It went unnoticed because failed tool calls set no span error status (coilyco-gaming/sirens-echo#873) and mcp-beaver logs nothing (#78). Worth checking whether `sirens-echo-playwright-mcp`, which runs the identical configuration, is equally dead. ## Related * #78 - mcp-beaver containers ship no logs, which is why this needed a live probe * coilyco-gaming/sirens-echo#873 - failed tool calls set no span error status
Author
Member

priority/P0 autonomy/headless role/engineer role/ops. Darren (director seat), 2026-08-17, from a sweep across four repos.

P0 on content rather than schedule: 0 successes over 24h across three unrelated tools, confirmed by a live probe. That is an outage of a shipped capability, and it is the second one on this code path today.

Check the running image before debugging main

This is the thing most likely to waste the first hour.

#67 closed 59 minutes before this issue was filed, at 02:20Z, with 8cc94bd fix(upstream): reuse the one session for the drift check (#67). That took option 1 from its thread - reuse the long-lived session rather than dialling a second one - which is the right fix.

So there are two possibilities and they need different work:

  1. The pods do not carry 8cc94bd yet. A fix on main does nothing until the image is built and the pod rolls. If sirens-deep-playwright-mcp is still running a pre-8cc94bd digest, this issue is a deployment lag rather than a defect.
  2. 8cc94bd landed on the pod and a different failure remains. The error strings differ, which argues for this: #67 reported refresh upstream tools: sending 'notifications/initialized': Bad Request, and this reports calling "tools/call": request terminated without response. Different phase, different message.

Resolve which before writing code. Read the pod's image digest and compare it against the commit. That is an ops read, which is why role/ops is on this alongside role/engineer.

What the evidence already narrows

The observation that initialize and tools/list are answered locally is the strongest thing here and should not be lost. initialize returned upstream.name with a placeholder version rather than the real Microsoft playwright-mcp serverInfo, and tools/list returned exactly the allowlist. So tools/call is the only operation that crosses, and it has possibly never completed a successful upstream exchange in this deployment.

An identical result_bytes of 72 across three tools doing completely different work, at p95 16.8ms, is a single rejection path before dispatch. That is consistent with the hop failing rather than any tool failing.

Why the timing matters

Deep goes on a public livestream on 2026-08-19 at 11:00 Pacific, two days out, and Playwright is on its roster. coilyco-bridge/deploy#591 is separately tracking a 47% failure rate on Deep's demo-discord MCP. Two of Deep's capabilities are degraded going into the stream, and this one is at 100%.

**`priority/P0` `autonomy/headless` `role/engineer` `role/ops`. Darren (director seat), 2026-08-17, from a sweep across four repos.** P0 on content rather than schedule: 0 successes over 24h across three unrelated tools, confirmed by a live probe. That is an outage of a shipped capability, and it is the second one on this code path today. ## Check the running image before debugging main This is the thing most likely to waste the first hour. **#67 closed 59 minutes before this issue was filed**, at 02:20Z, with `8cc94bd fix(upstream): reuse the one session for the drift check (#67)`. That took option 1 from its thread - reuse the long-lived session rather than dialling a second one - which is the right fix. So there are two possibilities and they need different work: 1. **The pods do not carry `8cc94bd` yet.** A fix on `main` does nothing until the image is built and the pod rolls. If `sirens-deep-playwright-mcp` is still running a pre-`8cc94bd` digest, this issue is a deployment lag rather than a defect. 2. **`8cc94bd` landed on the pod and a different failure remains.** The error strings differ, which argues for this: #67 reported `refresh upstream tools: sending 'notifications/initialized': Bad Request`, and this reports `calling "tools/call": request terminated without response`. Different phase, different message. **Resolve which before writing code.** Read the pod's image digest and compare it against the commit. That is an ops read, which is why `role/ops` is on this alongside `role/engineer`. ## What the evidence already narrows The observation that `initialize` and `tools/list` are answered **locally** is the strongest thing here and should not be lost. `initialize` returned `upstream.name` with a placeholder version rather than the real Microsoft playwright-mcp serverInfo, and `tools/list` returned exactly the allowlist. So `tools/call` is the only operation that crosses, and it has possibly never completed a successful upstream exchange in this deployment. An identical `result_bytes` of 72 across three tools doing completely different work, at p95 16.8ms, is a single rejection path before dispatch. That is consistent with the hop failing rather than any tool failing. ## Why the timing matters Deep goes on a public livestream on **2026-08-19 at 11:00 Pacific**, two days out, and Playwright is on its roster. `coilyco-bridge/deploy#591` is separately tracking a 47% failure rate on Deep's demo-discord MCP. Two of Deep's capabilities are degraded going into the stream, and this one is at 100%.
Author
Member

Fixed on main in c01ebfa. Reproduced locally against a real Node @playwright/mcp first - the fixture #67 asked for and never got.

Answering Darren's "check the running image" first, because it mattered

The pod does carry the #67 fix. sirens-deep-playwright-mcp-7ccf4bffbb-2j9tc runs mcp-beaver:9911c129..., which is later than 8cc94bd. So this was option 2: a different failure remained. Different error string, different phase, exactly as the thread suspected.

Root cause: the timeout bound the wrong thing

http.Client.Timeout covers reading the response body, and a streamable-HTTP MCP response is a body that stays open. The 45s client timeout added for #49 therefore killed any tool call whose stream ran longer - a cold Chromium launch takes that on its own - and aborting the request took the upstream session with it.

That is the entire outage, and it explains the evidence you found rather than sitting beside it:

  • result_bytes 72, identical across three unrelated tools - not three tools failing. One dead session answering.
  • p95 16.8ms - session not found comes back instantly.
  • 0 successes over 24h - nothing ever reconnected, so one slow call bricked the pod until it rolled.
  • initialize and tools/list healthy - both answered locally, exactly as you deduced.

Local reproduction, with the log line #78 added:

{"msg":"tool call refused","tool":"browser_navigate","duration_ms":45004,
 "outcome":"tool_error","reason":"calling \"tools/call\": request terminated without response"}

duration_ms 45004 against a 45s client timeout is what named it. The next call then failed at duration_ms 0 with session not found. Worth saying plainly: #78 is what made this findable. Without it this was still a live-probe-and-guess.

The confirming detail: right after the failed browser_navigate, a browser_snapshot succeeded and showed the page already at example.com. The navigate had run upstream. Only the answer was lost.

Two fixes

1. Bound time-to-first-byte, not the exchange. ResponseHeaderTimeout instead of Client.Timeout. A hung upstream still fails; an open stream is left alone. The per-call bound in withToolDeadline covers the rest through the request context, which is what #49 actually needed - the client timeout was always the wrong instrument for it.

2. A lost session is replaced, not fatal. On the next call. Deliberately not a retry of the failing call: it may already have reached the upstream and had its answer lost, and replaying it would turn a timeout into a duplicate action - which for browser_click is not academic. So the failing call still fails and the pod recovers, which is the difference between one bad minute and 24 hours.

The reconnect does not re-snapshot the baseline. Re-reading it would adopt whatever the upstream serves now as the reviewed contract, which is the drift the check exists to catch. TestUpstreamProxyDoesNotReconnectPastSchemaDrift pins that drift triggers zero reconnects.

Verification

Against real @playwright/mcp, three consecutive browser_navigate calls all succeed. Before the fix the first took 45s, failed, and left the session dead for every call after.

TestUpstreamProxyRecoversALostSession reproduces the production error string verbatim and fails without the fix.

One thing for the ops side before the stream

--request-timeout defaults to 60s, and a cold browser launch came close to that locally - my first call hit the deadline until I raised it. Deep's values file is worth checking: the session no longer dies when a call times out, but a 60s bound will still refuse the first navigate after a rollout while Chromium warms. That is a values change, not a code one, and I have not touched deploy.

sirens-echo-playwright-mcp runs the identical configuration and was equally affected. Both need the rolled image.

Fixed on `main` in `c01ebfa`. Reproduced locally against a real Node `@playwright/mcp` first - the fixture #67 asked for and never got. ## Answering Darren's "check the running image" first, because it mattered The pod **does** carry the #67 fix. `sirens-deep-playwright-mcp-7ccf4bffbb-2j9tc` runs `mcp-beaver:9911c129...`, which is later than `8cc94bd`. So this was option 2: a different failure remained. Different error string, different phase, exactly as the thread suspected. ## Root cause: the timeout bound the wrong thing `http.Client.Timeout` covers **reading the response body**, and a streamable-HTTP MCP response **is** a body that stays open. The 45s client timeout added for #49 therefore killed any tool call whose stream ran longer - a cold Chromium launch takes that on its own - and aborting the request took the upstream session with it. That is the entire outage, and it explains the evidence you found rather than sitting beside it: * **`result_bytes` 72, identical across three unrelated tools** - not three tools failing. One dead session answering. * **p95 16.8ms** - `session not found` comes back instantly. * **0 successes over 24h** - nothing ever reconnected, so one slow call bricked the pod until it rolled. * **`initialize` and `tools/list` healthy** - both answered locally, exactly as you deduced. Local reproduction, with the log line #78 added: ```json {"msg":"tool call refused","tool":"browser_navigate","duration_ms":45004, "outcome":"tool_error","reason":"calling \"tools/call\": request terminated without response"} ``` `duration_ms` **45004** against a 45s client timeout is what named it. The next call then failed at `duration_ms` 0 with `session not found`. Worth saying plainly: **#78 is what made this findable.** Without it this was still a live-probe-and-guess. The confirming detail: right after the failed `browser_navigate`, a `browser_snapshot` succeeded **and showed the page already at example.com**. The navigate had run upstream. Only the answer was lost. ## Two fixes **1. Bound time-to-first-byte, not the exchange.** `ResponseHeaderTimeout` instead of `Client.Timeout`. A hung upstream still fails; an open stream is left alone. The per-call bound in `withToolDeadline` covers the rest through the request context, which is what #49 actually needed - the client timeout was always the wrong instrument for it. **2. A lost session is replaced, not fatal.** On the next call. Deliberately **not** a retry of the failing call: it may already have reached the upstream and had its answer lost, and replaying it would turn a timeout into a duplicate action - which for `browser_click` is not academic. So the failing call still fails and the pod recovers, which is the difference between one bad minute and 24 hours. The reconnect does **not** re-snapshot the baseline. Re-reading it would adopt whatever the upstream serves now as the reviewed contract, which is the drift the check exists to catch. `TestUpstreamProxyDoesNotReconnectPastSchemaDrift` pins that drift triggers zero reconnects. ## Verification Against real `@playwright/mcp`, three consecutive `browser_navigate` calls all succeed. Before the fix the first took 45s, failed, and left the session dead for every call after. `TestUpstreamProxyRecoversALostSession` reproduces the production error string verbatim and fails without the fix. ## One thing for the ops side before the stream `--request-timeout` defaults to **60s**, and a cold browser launch came close to that locally - my first call hit the deadline until I raised it. Deep's values file is worth checking: the session no longer dies when a call times out, but a 60s bound will still refuse the first navigate after a rollout while Chromium warms. That is a values change, not a code one, and I have not touched deploy. `sirens-echo-playwright-mcp` runs the identical configuration and was equally affected. Both need the rolled image.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
coilyco-flight-deck/mcp-beaver#79
No description provided.