Repository navigation
Auto discovery timeout rejects a late probe response during legacy initialization #1400
Description
Describe the bug
An MCP server that takes longer than the client's ten-second discovery timeout to start can fail to connect if it subsequently answers the discovery request. The same server, with the same startup delay, connects successfully if it ignores discovery instead.
The issue is the handling of an outstanding discovery response after timeout fallback has begun. The controlled comparison below holds startup latency constant: a twelve-second delay is accepted when discovery is ignored, but a correctly correlated late discovery reply causes connection failure.
This is reproduced with the unmodified official aaif-goose/goose v1.56.0 macOS arm64 CLI, whose release lockfile selects rmcp 3.4.1. No fork, model prompt, API credentials, or external MCP service is required.
The fixture is a 49-line Python standard-library server supporting the 2025-11-25 initialization handshake and one echo tool. It waits before reading stdin, then answers unsupported server/discover with a correctly correlated -32601 error and answers initialize normally. It neither changes request IDs nor deliberately exits on discovery.
To Reproduce
- Download the official Goose v1.56.0 macOS arm64 CLI and verify its checksum as described in
README.mdunder Reproducer files and evidence below. - Save
reproduce.pyandslow_mcp.pyfrom Reproducer files and evidence below into the same directory, then change into it. - Run the following controls and failing cases. Each output directory must be new.
python3 reproduce.py --goose /absolute/path/to/goose --output runs/fast --delay 0 --expect success
python3 reproduce.py --goose /absolute/path/to/goose --output runs/ignored --delay 12 --ignore-discover --expect success
python3 reproduce.py --goose /absolute/path/to/goose --output runs/slow-1 --delay 12 --expect missing
python3 reproduce.py --goose /absolute/path/to/goose --output runs/slow-2 --delay 12 --expect missingThe driver uses Goose's ACP session creation and tool-list/call endpoints without submitting a model prompt. --expect missing asserts the observed bug; after a fix, these cases should pass with --expect success.
| Startup delay | Discovery response | Observed result |
|---|---|---|
| 0 seconds | Correlated -32601 error |
Initialization succeeds; echo returns pong |
| 12 seconds | Discovery ignored | Initialization succeeds; echo returns pong |
| 12 seconds | Correlated -32601 error |
Extension fails; tool unavailable, reproduced twice |
In the failing cases, the fixture reads discovery request ID 0 and initialization request ID 1 after becoming ready. It writes the discovery error with ID 0, then a valid initialization result with ID 1. Goose never sends notifications/initialized.
Expected behavior
Once Auto chooses to continue with legacy initialization after the discovery timeout, a late response to the earlier probe should not be mistaken for the initialization response and fail the connection. The legacy fixture should connect as it does in the ignored-discovery control.
An overall startup deadline can still be appropriate. This report does not require removing timeouts or waiting indefinitely; it concerns correctly handling outstanding requests when the SDK elects to continue on the same transport. The appropriate fix also needs to preserve the lifecycle rules for a late successful discovery response from a modern server.
Logs
The upstream runtime warning is:
failed to start extension
extension: slow
error: process quit before initialization: stderr =
ACP session creation still succeeds, the extension's tool list is empty, and its tool call returns:
{"code":-32602,"message":"Invalid params","data":"tool not found"}All four test invocations passed their assertions. Each Goose process exited normally after the driver closed stdin. Complete fixture-side traces and result summaries are included below.
Additional context
Why intermittent startup delays matter
We investigated this after intermittent extension initialization failures in a Goose fork, typically reported after the fork had been running for a long time, the laptop was left idle or slept, and the user returned to the same chat. The extensions normally start quickly. Isolated measurements using the installed launchers, interpreters, and dependencies gave the following launch-to-first-protocol-response times, including launcher work and Python imports:
| Test | Notebook extension | Visualization extension |
|---|---|---|
| Individual starts, three repetitions each | 0.51–0.69 seconds | 0.67–1.01 seconds |
| Three of each started concurrently | About 0.87 seconds | About 1.32 seconds |
The Goose fork reconnects on resume and starts many extensions concurrently while the laptop and other applications are also waking up. Competition for CPU and filesystem access can plausibly delay otherwise fast servers beyond the discovery timeout. This is our hypothesis for the intermittent delays, not a measured cause: the isolated tests were warm starts and did not recreate laptop wake or the full concurrent startup workload. None crossed ten seconds.
The incident's response-ID errors and the installed SDK's error paths strongly suggest timeout fallback followed by a late discovery response. Historical logs lack the per-process/session identifiers and wire timestamps needed to prove that sequence for each affected extension. The synthetic twelve-second delay makes the timing condition deterministic; it is not a measurement of normal server startup.
The upstream reproduction above isolates the SDK behavior without requiring sleep or concurrent launches.
Suspected SDK cause
ClientLifecycleMode::Auto times out discovery after ten seconds and invokes legacy_startup on the same transport. Its response reader strictly checks the next response against the initialization request ID. A delayed discovery response can therefore be rejected as an uncorrelated response while the client is waiting for initialization.
This explanation comes from source inspection and the controlled traces. The tested upstream Goose binary exposes only the generic warning above, not the nested response-ID error. Fixture timestamps record when the server reads/writes messages; they do not independently measure when Goose sent them.
The relevant timeout, same-transport fallback, and response-ID check are present in the inspected Rust SDK main revision cd88056. That revision was inspected, not executed.
Related: #1142 / #1149 added the bounded discovery wait for servers that never respond. This report concerns servers that respond after that wait. Goose #13177 concerns servers exiting on discovery; this fixture remains alive and answers initialization.
Environment and scope
- macOS 14.8.9, arm64; Python 3.14.6.
- Official Goose v1.56.0, source commit
9949cf926cd42f1d128b9991ed23a496ecace896; archive checksum verified against GitHub's release metadata. - Test uses a fresh Goose config/session directory, disabled keyring access, and a dummy provider endpoint on loopback. Goose can discover home skill metadata; those notifications and raw profiles are excluded from the accompanying evidence.
- This reproduces slow startup only. It does not test OS sleep, reconnect recovery, a fix, or runtime behavior on current main.
The reproducer files and evidence are included in collapsible sections below: scripts, README, provenance, verification record, checksums, and the four final traces/summaries. No binary or personal session logs are included.
AI assistance disclosure
OpenAI Codex agents assisted with the source and log investigation, authored and ran the reproducer and isolated startup measurements, independently reviewed the reproducer, and drafted this report. The observations above come from recorded tool executions; hypotheses and untested behavior are identified explicitly.
Reproducer files and evidence
Save each expanded file using its displayed relative path. The two Python scripts are sufficient to run the reproducer; the other files document the recorded results. File contents are unchanged from the independently reviewed bundle.
README.md
# Slow legacy MCP startup reproducer for upstream Goose
This reproducer uses the unmodified official `aaif-goose/goose` **v1.56.0** CLI,
not the SB Agent fork. It exercises Goose's MCP client through ACP without
submitting a model prompt. The fixture is a 49-line Python standard-library
server; the larger driver starts Goose, records the exchange, checks outcomes,
and cleans up.
The fixture supports the 2025-11-25 initialization handshake and one harmless
`echo` tool returning `pong`. It answers the unsupported `server/discover` method
with a correctly correlated JSON-RPC `-32601` error. `--delay 12` adds twelve
seconds of startup time before the server reads stdin; it does not change IDs,
corrupt messages, exit on discovery, or reject initialization. An additional
control ignores discovery while keeping the same twelve-second startup delay.
## Run
Requires Python 3 and an upstream Goose CLI on macOS or Linux. No Python packages
or API credentials are needed. Acquire the official binary separately from
running it. On macOS arm64:
```sh
mkdir upstream
curl -fL https://github.com/aaif-goose/goose/releases/download/v1.56.0/goose-aarch64-apple-darwin.tar.bz2 -o upstream/goose.tar.bz2
shasum -a 256 upstream/goose.tar.bz2
tar -xjf upstream/goose.tar.bz2 -C upstream
```
The archive SHA-256 must be
`62d806417b19be167474297eaaec7783ff9917f4fa772e781e977f2bdc155163`.
Then, in separate invocations:
```sh
python3 reproduce.py --goose upstream/goose --output runs/fast --delay 0 --expect success
python3 reproduce.py --goose upstream/goose --output runs/ignored --delay 12 --ignore-discover --expect success
python3 reproduce.py --goose upstream/goose --output runs/slow-1 --delay 12 --expect missing
python3 reproduce.py --goose upstream/goose --output runs/slow-2 --delay 12 --expect missing
```
Each output directory must be new. A completed assertion check exits zero;
`--expect missing` explicitly checks for the currently reproduced bug, not the
desired fixed behavior. Once fixed, the slow case should pass with
`--expect success`. Each ACP request has a sixty-second deadline. The driver
closes stdin, then uses bounded process-group termination if Goose does not exit.
On the original test machine, every command additionally used
`--runner /absolute/path/to/cortex-run.py`. That optional local-policy
wrapper waits twenty seconds before each native binary launch. It is not part of
the reproducer and is not required on other machines unless their policy requires
it. No native executable was built or modified during testing.
## Expected and observed behavior
All three server behaviors should permit the supported legacy handshake. The
late response to the discovery probe should not be mistaken for the response to
the later initialization request.
| Case | Startup delay | Discovery behavior | Observed on v1.56.0 |
| --- | ---: | --- | --- |
| Fast control | 0 s | Reply `-32601`, matching ID | Tool listed; returns `pong` |
| Ignored-probe control | 12 s | No response | Tool listed; returns `pong` |
| Late response | 12 s | Reply `-32601`, matching ID | Extension missing; tool call fails |
The late-response case is repeated twice. `summary.json` records the Goose
version, tool availability, tool-call response, extension warnings, and process
exit status. `mcp.jsonl` records the complete fixture-side protocol exchange with
monotonic times relative to fixture startup. These timestamps measure when the
fixture reads/writes a message, not when Goose sent it.
The affected exchange is:
1. Goose sends discovery with ID 0; its ten-second probe timeout elapses.
2. Goose sends initialization with ID 1.
3. The fixture becomes ready after twelve seconds and returns the discovery
error with ID 0, followed by a valid initialization response with ID 1.
4. Goose does not send `notifications/initialized`; the extension is absent.
The timeout and response matching are established by source inspection, while
the fixture trace directly records steps 3 and 4 and the requests it receives.
Upstream Goose's warning is only `process quit before initialization: stderr =`;
it does **not** expose the nested response-ID mismatch in this tested release.
Do not quote an `expected 1, got 0` error as observed upstream output.
## Isolation and scope
The driver sets a fresh `GOOSE_PATH_ROOT`, clears inherited provider variables,
disables keyring access, and supplies a dummy OpenAI key with endpoint
`http://127.0.0.1:9`. It sends no `session/prompt`; there are no LLM inference
requests. Goose may attempt model-inventory queries to that unused local port
and its normal public `models.dev` catalog refresh; neither is needed for the
test. The recorded runs used a network-restricted execution environment.
Goose still discovers home-directory skill metadata. The driver omits ACP
notifications from `acp.jsonl` because those notifications may contain personal
skill descriptions. Config/session writes are isolated; this is not a complete
filesystem sandbox. Public evidence should include only `summary.json` and
`mcp.jsonl`, not Goose's full profile or raw logs.
This is a deterministic slow-start handshake reproducer. It does **not** put the
laptop to sleep, test reconnect recovery, establish that all extension-loss
incidents have this cause, or test a fix. The ignored-probe case isolates the
effect of a late discovery response from slow startup alone.
## Provenance and source check
- Official release: https://github.com/aaif-goose/goose/releases/tag/v1.56.0
- Release source commit: `9949cf926cd42f1d128b9991ed23a496ecace896`.
- Tested binary SHA-256:
`a64c2bf0df3a55ab18db7e65ab180cd17f91331fdf3c873fed1f46d98cd3bb92`.
- Release `Cargo.lock` selects `rmcp 3.4.1`.
- Goose main inspected at `8a16788137c8af25f9d6d17ee87bbedb53ea9325`;
`crates/goose/src/agents/mcp_client.rs` is byte-identical to the release file.
- Rust SDK main inspected at `cd88056ffdc97756fbd98e5a12bbeb41758f0ce8`;
`crates/rmcp/src/service/client.rs` still has a ten-second auto-discovery timeout,
fallback on the same transport, and strict response-ID matching.
Runtime verification applies to the release binary only. Inspection of current
main is not a runtime test of main.
reproduce.py
"""Exercise a real Goose binary over ACP, without submitting an LLM prompt."""
import argparse
import json
import os
from pathlib import Path
import queue
import signal
import subprocess
import sys
import threading
import time
def run_case(goose, runner, output, delay, ignore_discover):
output.mkdir(parents=True)
root = output.resolve()
(root / "goose-home" / "config").mkdir(parents=True)
(root / "goose-home" / "config" / "config.yaml").write_text(
"GOOSE_PROVIDER: openai\nGOOSE_MODEL: gpt-4o-mini\nGOOSE_MODE: auto\nextensions: {}\n"
)
env = {key: os.environ[key] for key in ("PATH", "TMPDIR", "SYSTEMROOT") if key in os.environ}
env.update(GOOSE_PATH_ROOT=str(root / "goose-home"), GOOSE_PROVIDER="openai",
GOOSE_MODEL="gpt-4o-mini", GOOSE_MODE="auto", OPENAI_API_KEY="unused-repro-key",
OPENAI_HOST="http://127.0.0.1:9", GOOSE_DISABLE_KEYRING="1", LANG="C", LC_ALL="C")
command = ([sys.executable, str(runner)] if runner else []) + [str(goose), "acp"]
messages = queue.Queue()
transcript = (root / "acp.jsonl").open("w", buffering=1)
stderr = (root / "stderr.log").open("w")
process = subprocess.Popen(command, stdin=subprocess.PIPE, stdout=subprocess.PIPE,
stderr=stderr, text=True, env=env, cwd=root,
start_new_session=True)
def read_output():
for line in process.stdout:
try:
message = json.loads(line)
except json.JSONDecodeError:
transcript.write(json.dumps({"stdout": line.rstrip()}) + "\n")
continue
# Notifications may include personal skill descriptions; retain only RPC responses.
if "method" not in message:
transcript.write(json.dumps({"direction": "in", "message": message}) + "\n")
messages.put(message)
messages.put(None)
thread = threading.Thread(target=read_output, daemon=True)
thread.start()
next_id = 0
def request(method, params):
nonlocal next_id
next_id += 1
message = {"jsonrpc": "2.0", "id": next_id, "method": method, "params": params}
transcript.write(json.dumps({"direction": "out", "message": message}) + "\n")
process.stdin.write(json.dumps(message) + "\n")
process.stdin.flush()
deadline = time.monotonic() + 60
while True:
response = messages.get(timeout=max(0.01, deadline - time.monotonic()))
if response is None:
raise RuntimeError(f"Goose closed stdout (exit {process.poll()})")
if response.get("id") == next_id and "method" not in response:
return response
result = {"delay_seconds": delay, "ignore_discover": ignore_discover}
try:
result["initialize"] = request("initialize", {
"protocolVersion": 1, "clientCapabilities": {},
"clientInfo": {"name": "repro", "version": "1"}})
result["session"] = request("session/new", {
"cwd": str(root),
"mcpServers": [{"name": "slow", "command": sys.executable,
"args": [str(Path(__file__).with_name("slow_mcp.py").resolve()), "--delay", str(delay),
"--wire", str(root / "mcp.jsonl")] + (["--ignore-discover"] if ignore_discover else []),
"env": []}]})
session_id = result["session"]["result"]["sessionId"]
result["tools"] = request("_goose/unstable/tools/list", {
"sessionId": session_id, "extensionName": "slow"})
result["call"] = request("_goose/unstable/tools/call", {
"sessionId": session_id, "extensionName": "slow", "name": "slow__echo", "arguments": {}})
finally:
process.stdin.close()
try:
process.wait(timeout=5)
except subprocess.TimeoutExpired:
os.killpg(process.pid, signal.SIGTERM)
try:
process.wait(timeout=5)
except subprocess.TimeoutExpired:
os.killpg(process.pid, signal.SIGKILL)
process.wait(timeout=5)
thread.join(timeout=2)
result["process_exit"] = process.returncode
stderr.close()
transcript.close()
(root / "result.json").write_text(json.dumps(result, indent=2) + "\n")
return result
def main():
parser = argparse.ArgumentParser(description=__doc__)
parser.add_argument("--goose", required=True, type=Path)
parser.add_argument("--runner", type=Path, help="Optional cortex-run.py native executable wrapper")
parser.add_argument("--output", required=True, type=Path)
parser.add_argument("--delay", type=float, default=0)
parser.add_argument("--ignore-discover", action="store_true")
parser.add_argument("--expect", choices=("success", "missing"), required=True)
args = parser.parse_args()
result = run_case(args.goose.resolve(), args.runner, args.output, args.delay, args.ignore_discover)
if result["process_exit"] in (-signal.SIGKILL, 137):
raise SystemExit("Goose received SIGKILL; stop and investigate before retrying")
wire = [json.loads(line) for line in (args.output / "mcp.jsonl").read_text().splitlines()]
initialized = any(e["direction"] == "in" and e["message"].get("method") == "notifications/initialized"
for e in wire)
tools = [t["name"] for t in result["tools"].get("result", {}).get("tools", [])]
errors = []
for log in (args.output / "goose-home" / "state" / "logs").rglob("*.log"):
for line in log.read_text().splitlines():
entry = json.loads(line)
if entry.get("fields", {}).get("extension") == "slow":
errors.append(entry)
summary = {"delay_seconds": args.delay, "ignore_discover": args.ignore_discover,
"goose_version": result["initialize"].get("result", {}).get("agentInfo"),
"session_created": "result" in result["session"], "tools": tools,
"call": result["call"], "initialized_notification_received": initialized,
"extension_log": errors, "process_exit": result["process_exit"]}
(args.output / "summary.json").write_text(json.dumps(summary, indent=2) + "\n")
print(json.dumps(summary, indent=2))
assert result["process_exit"] == 0, "Goose did not exit normally"
assert "result" in result["tools"], "tools/list itself failed"
assert any(e["direction"] == "in" and e["message"].get("method") == "initialize" for e in wire), \
"Fixture never received initialize; this is not the intended test"
if args.expect == "success":
assert tools == ["slow__echo"] and initialized
assert result["call"].get("result", {}).get("content") == [{"type": "text", "text": "pong"}]
else:
assert not tools and not initialized
assert result["call"].get("error", {}).get("data") == "tool not found"
assert any("failed to start extension" in e["fields"].get("message", "") for e in errors)
if __name__ == "__main__":
main()slow_mcp.py
"""A legacy MCP server whose only variable is time spent starting up."""
import argparse
import json
import sys
import time
parser = argparse.ArgumentParser()
parser.add_argument("--delay", type=float, default=0)
parser.add_argument("--wire", required=True)
parser.add_argument("--ignore-discover", action="store_true")
args = parser.parse_args()
started = time.monotonic()
with open(args.wire, "w", buffering=1) as wire:
def record(direction, message):
wire.write(json.dumps({"seconds": round(time.monotonic() - started, 4),
"direction": direction, "message": message}) + "\n")
time.sleep(args.delay)
initialized = False
for line in sys.stdin:
request = json.loads(line)
record("in", request)
method = request.get("method")
if method == "notifications/initialized":
initialized = True
if "id" not in request:
continue
if method == "server/discover" and args.ignore_discover:
continue
response = {"jsonrpc": "2.0", "id": request["id"]}
if method == "initialize":
response["result"] = {"protocolVersion": "2025-11-25",
"capabilities": {"tools": {}},
"serverInfo": {"name": "slow-legacy", "version": "1"}}
elif method == "ping":
response["result"] = {}
elif method == "tools/list" and initialized:
response["result"] = {"tools": [{"name": "echo", "description": "Returns pong.",
"inputSchema": {"type": "object", "properties": {}}}]}
elif method == "tools/call" and initialized and request.get("params", {}).get("name") == "echo":
response["result"] = {"content": [{"type": "text", "text": "pong"}], "isError": False}
else:
response["error"] = {"code": -32601, "message": "Method not found"}
record("out", response)
try:
print(json.dumps(response), flush=True)
except BrokenPipeError:
breakprovenance.json
{"asset":{"apiUrl":"https://api.github.com/repos/aaif-goose/goose/releases/assets/669602483","contentType":"raw","createdAt":"2026-10-23T15:49:51Z","digest":"sha256:62d806417b19be167474297eaaec7783ff9917f4fa772e781e977f2bdc155163","downloadCount":780,"id":"RA_kwDOMneZ984n6VKz","label":"","name":"goose-aarch64-apple-darwin.tar.bz2","size":51175043,"state":"uploaded","updatedAt":"2026-10-23T15:49:53Z","url":"https://github.com/aaif-goose/goose/releases/download/v1.56.0/goose-aarch64-apple-darwin.tar.bz2"},"tagName":"v1.56.0","url":"https://github.com/aaif-goose/goose/releases/tag/v1.56.0"}VERIFICATION.txt
Verification date: 2026-10-27
Host: macOS 14.8.9, arm64
Python: 3.14.6
Goose: official upstream aaif-goose/goose v1.56.0 arm64 release binary
Source: 9949cf926cd42f1d128b9991ed23a496ecace896
Archive checksum: matches GitHub release API digest (see provenance.json)
Native binary checksum: a64c2bf0df3a55ab18db7e65ab180cd17f91331fdf3c873fed1f46d98cd3bb92
Executed sequentially from the artifact root using reproduce.py and slow_mcp.py
with exactly the hashes in SHA256SUMS. Each invocation also used the local
--runner option pointing at the machine's cortex-run.py policy wrapper.
The wrapper waited 20 seconds before starting the unchanged native executable.
python3 reproduce.py --goose upstream/goose --output evidence/final-fast --delay 0 --expect success
python3 reproduce.py --goose upstream/goose --output evidence/final-ignore --delay 12 --ignore-discover --expect success
python3 reproduce.py --goose upstream/goose --output evidence/final-slow-1 --delay 12 --expect missing
python3 reproduce.py --goose upstream/goose --output evidence/final-slow-2 --delay 12 --expect missing
Result: all four invocations completed with exit 0 and all assertions passed.
Both controls listed slow__echo and returned pong. Both late-response runs
omitted slow__echo, did not send notifications/initialized, logged extension
startup failure, and returned tool not found from ACP tools/call.
Each Goose process exited normally with code 0 after its stdin closed.
No source compilation, model prompt, actual sleep/resume, or fix testing.
No running process/job remains from the final verification invocation.
Public evidence selection: complete fixture-side mcp.jsonl plus summary.json
for each final case. Summary retains only fixture-related extension warnings.
Goose profile/session database, provider inventory, ACP skill notifications,
raw logs and exploratory harness runs are not part of this bundle.
The local acp.jsonl omits notifications because they may contain personal
skill descriptions. The bundled MCP traces are unedited and show a temporary
test working directory only in the successful tool-call metadata.
Source-only comparison: Goose main 8a16788137c8af25f9d6d17ee87bbedb53ea9325
has a byte-identical mcp_client.rs to v1.56.0. Rust SDK main
cd88056ffdc97756fbd98e5a12bbeb41758f0ce8 still contains the relevant timeout,
same-transport fallback, and response-ID check. Neither main was run.
evidence/final-fast/summary.json
{
"delay_seconds": 0.0,
"ignore_discover": false,
"goose_version": {
"name": "goose",
"version": "1.56.0"
},
"session_created": true,
"tools": [
"slow__echo"
],
"call": {
"jsonrpc": "2.0",
"id": 4,
"result": {
"content": [
{
"type": "text",
"text": "pong"
}
],
"isError": false
}
},
"initialized_notification_received": true,
"extension_log": [],
"process_exit": 0
}evidence/final-ignore/summary.json
{
"delay_seconds": 12.0,
"ignore_discover": true,
"goose_version": {
"name": "goose",
"version": "1.56.0"
},
"session_created": true,
"tools": [
"slow__echo"
],
"call": {
"jsonrpc": "2.0",
"id": 4,
"result": {
"content": [
{
"type": "text",
"text": "pong"
}
],
"isError": false
}
},
"initialized_notification_received": true,
"extension_log": [],
"process_exit": 0
}evidence/final-slow-1/summary.json
{
"delay_seconds": 12.0,
"ignore_discover": false,
"goose_version": {
"name": "goose",
"version": "1.56.0"
},
"session_created": true,
"tools": [],
"call": {
"jsonrpc": "2.0",
"id": 4,
"error": {
"code": -32602,
"message": "Invalid params",
"data": "tool not found"
}
},
"initialized_notification_received": false,
"extension_log": [
{
"timestamp": "2026-10-27T22:42:15.159594Z",
"level": "WARN",
"fields": {
"message": "failed to start extension",
"extension": "slow",
"error": "process quit before initialization: stderr = "
},
"target": "goose::agents::extension_manager"
}
],
"process_exit": 0
}evidence/final-slow-2/summary.json
{
"delay_seconds": 12.0,
"ignore_discover": false,
"goose_version": {
"name": "goose",
"version": "1.56.0"
},
"session_created": true,
"tools": [],
"call": {
"jsonrpc": "2.0",
"id": 4,
"error": {
"code": -32602,
"message": "Invalid params",
"data": "tool not found"
}
},
"initialized_notification_received": false,
"extension_log": [
{
"timestamp": "2026-10-27T22:42:47.516686Z",
"level": "WARN",
"fields": {
"message": "failed to start extension",
"extension": "slow",
"error": "process quit before initialization: stderr = "
},
"target": "goose::agents::extension_manager"
}
],
"process_exit": 0
}evidence/final-fast/mcp.jsonl
{"seconds": 0.0002, "direction": "in", "message": {"jsonrpc": "2.0", "id": 0, "method": "server/discover", "params": {"_meta": {"io.modelcontextprotocol/protocolVersion": "2026-07-28", "io.modelcontextprotocol/clientInfo": {"name": "repro", "version": "1"}, "io.modelcontextprotocol/clientCapabilities": {"extensions": {}, "roots": {}, "elicitation": {}}}}}}
{"seconds": 0.0003, "direction": "out", "message": {"jsonrpc": "2.0", "id": 0, "error": {"code": -32601, "message": "Method not found"}}}
{"seconds": 0.0005, "direction": "in", "message": {"jsonrpc": "2.0", "id": 1, "method": "initialize", "params": {"protocolVersion": "2025-11-25", "capabilities": {"extensions": {}, "roots": {}, "elicitation": {}}, "clientInfo": {"name": "repro", "version": "1"}}}}
{"seconds": 0.0005, "direction": "out", "message": {"jsonrpc": "2.0", "id": 1, "result": {"protocolVersion": "2025-11-25", "capabilities": {"tools": {}}, "serverInfo": {"name": "slow-legacy", "version": "1"}}}}
{"seconds": 0.0006, "direction": "in", "message": {"jsonrpc": "2.0", "method": "notifications/initialized"}}
{"seconds": 0.0083, "direction": "in", "message": {"jsonrpc": "2.0", "id": 2, "method": "tools/list", "params": {"_meta": {"agent-session-id": "20261027_1", "progressToken": 0}}}}
{"seconds": 0.0084, "direction": "out", "message": {"jsonrpc": "2.0", "id": 2, "result": {"tools": [{"name": "echo", "description": "Returns pong.", "inputSchema": {"type": "object", "properties": {}}}]}}}
{"seconds": 0.0094, "direction": "in", "message": {"jsonrpc": "2.0", "id": 3, "method": "tools/call", "params": {"_meta": {"agent-session-id": "20261027_1", "agent-working-dir": "/private/tmp/goose-upstream-mcp-repro-20261027.7ccsCI/evidence/final-fast", "progressToken": 1}, "name": "echo", "arguments": {}}}}
{"seconds": 0.0094, "direction": "out", "message": {"jsonrpc": "2.0", "id": 3, "result": {"content": [{"type": "text", "text": "pong"}], "isError": false}}}
evidence/final-ignore/mcp.jsonl
{"seconds": 12.0104, "direction": "in", "message": {"jsonrpc": "2.0", "id": 0, "method": "server/discover", "params": {"_meta": {"io.modelcontextprotocol/protocolVersion": "2026-07-28", "io.modelcontextprotocol/clientInfo": {"name": "repro", "version": "1"}, "io.modelcontextprotocol/clientCapabilities": {"extensions": {}, "roots": {}, "elicitation": {}}}}}}
{"seconds": 12.0107, "direction": "in", "message": {"jsonrpc": "2.0", "id": 1, "method": "initialize", "params": {"protocolVersion": "2025-11-25", "capabilities": {"extensions": {}, "roots": {}, "elicitation": {}}, "clientInfo": {"name": "repro", "version": "1"}}}}
{"seconds": 12.0108, "direction": "out", "message": {"jsonrpc": "2.0", "id": 1, "result": {"protocolVersion": "2025-11-25", "capabilities": {"tools": {}}, "serverInfo": {"name": "slow-legacy", "version": "1"}}}}
{"seconds": 12.011, "direction": "in", "message": {"jsonrpc": "2.0", "method": "notifications/initialized"}}
{"seconds": 12.0166, "direction": "in", "message": {"jsonrpc": "2.0", "id": 2, "method": "tools/list", "params": {"_meta": {"agent-session-id": "20261027_1", "progressToken": 0}}}}
{"seconds": 12.0167, "direction": "out", "message": {"jsonrpc": "2.0", "id": 2, "result": {"tools": [{"name": "echo", "description": "Returns pong.", "inputSchema": {"type": "object", "properties": {}}}]}}}
{"seconds": 12.0203, "direction": "in", "message": {"jsonrpc": "2.0", "id": 3, "method": "tools/call", "params": {"_meta": {"agent-session-id": "20261027_1", "agent-working-dir": "/private/tmp/goose-upstream-mcp-repro-20261027.7ccsCI/evidence/final-ignore", "progressToken": 1}, "name": "echo", "arguments": {}}}}
{"seconds": 12.0203, "direction": "out", "message": {"jsonrpc": "2.0", "id": 3, "result": {"content": [{"type": "text", "text": "pong"}], "isError": false}}}
evidence/final-slow-1/mcp.jsonl
{"seconds": 12.0104, "direction": "in", "message": {"jsonrpc": "2.0", "id": 0, "method": "server/discover", "params": {"_meta": {"io.modelcontextprotocol/protocolVersion": "2026-07-28", "io.modelcontextprotocol/clientInfo": {"name": "repro", "version": "1"}, "io.modelcontextprotocol/clientCapabilities": {"extensions": {}, "roots": {}, "elicitation": {}}}}}}
{"seconds": 12.0106, "direction": "out", "message": {"jsonrpc": "2.0", "id": 0, "error": {"code": -32601, "message": "Method not found"}}}
{"seconds": 12.0107, "direction": "in", "message": {"jsonrpc": "2.0", "id": 1, "method": "initialize", "params": {"protocolVersion": "2025-11-25", "capabilities": {"extensions": {}, "roots": {}, "elicitation": {}}, "clientInfo": {"name": "repro", "version": "1"}}}}
{"seconds": 12.0108, "direction": "out", "message": {"jsonrpc": "2.0", "id": 1, "result": {"protocolVersion": "2025-11-25", "capabilities": {"tools": {}}, "serverInfo": {"name": "slow-legacy", "version": "1"}}}}
evidence/final-slow-2/mcp.jsonl
{"seconds": 12.0104, "direction": "in", "message": {"jsonrpc": "2.0", "id": 0, "method": "server/discover", "params": {"_meta": {"io.modelcontextprotocol/protocolVersion": "2026-07-28", "io.modelcontextprotocol/clientInfo": {"name": "repro", "version": "1"}, "io.modelcontextprotocol/clientCapabilities": {"extensions": {}, "roots": {}, "elicitation": {}}}}}}
{"seconds": 12.0107, "direction": "out", "message": {"jsonrpc": "2.0", "id": 0, "error": {"code": -32601, "message": "Method not found"}}}
{"seconds": 12.0107, "direction": "in", "message": {"jsonrpc": "2.0", "id": 1, "method": "initialize", "params": {"protocolVersion": "2025-11-25", "capabilities": {"extensions": {}, "roots": {}, "elicitation": {}}, "clientInfo": {"name": "repro", "version": "1"}}}}
{"seconds": 12.0108, "direction": "out", "message": {"jsonrpc": "2.0", "id": 1, "result": {"protocolVersion": "2025-11-25", "capabilities": {"tools": {}}, "serverInfo": {"name": "slow-legacy", "version": "1"}}}}
SHA256SUMS
7164db4244948bb2d3648248f7924b247b01e4ff7ace7148d77410ed29fe5667 reproduce.py
69b22406069aec0712bb1eace14a2e1ae8f506f6b2946ffeb62cf0cccbf549ba slow_mcp.py
7726adb24b3a61e20742ca4b0e7b51cc586fe3f545f6a65b61a8bccc737f7f3c README.md
2a760de44c2cb294ee6d774ae0ac44b71977680d21583bcccdcc4731500a5f37 provenance.json
b475123c5235bd578a379ec8a4f66d774eee8fa892519df74a81533e5637b437 VERIFICATION.txt
b4c432bdc792e7f00ea747922887289232bcf3f42cd05f7912caf2f8a8859891 evidence/final-fast/summary.json
7c7eac77f77c4df60c1b9e19e45415f3817beed93e6b5428abae8a875bbd8798 evidence/final-ignore/summary.json
07a99a6f5cde19438fa063e1f6f48a0151b790179b67167639c3bcda53a77f7e evidence/final-slow-1/summary.json
fb21a39d8c912917807d3a4fd9ffacb6cb93edb5bc2e0a68699914f720c7c686 evidence/final-slow-2/summary.json
1297750afef4390353a5a4b809382cdb8dc885f26af0f7874be5bf73787228c4 evidence/final-fast/mcp.jsonl
d06f4e7a5f57de7ee73d7927e96dcfcf39ca55cc02a18cded4901e4ffe36e497 evidence/final-ignore/mcp.jsonl
1edaf9927d8d55e05ce8e5f3eb426e122b9d1fbd06d1299a8ad7cff999ecc792 evidence/final-slow-1/mcp.jsonl
4b92802f5f88baddc67d8a58d04b92df19f3a28e3089e4c34f34a3e8e1ce3190 evidence/final-slow-2/mcp.jsonl
Activity
github-actions commentedon Oct 28, 2026
@gocamille is on triage rotation this week and is the reviewer for this one.
Codex labeled this bug / P1 (T-service). Please confirm or correct those labels.
Automated triage. Labels are a first pass and the assigned maintainer has the final say.
chore(deps): rmcp 0.16 → 3.5.x — constructors for the non-exhaustive …
gocamille commentedon Oct 30, 2026
Thanks for the detailed report, @arohou. I reproduced it on main: a late -32601 for the probe ends startup with
UncorrelatedErrorResponse { expected: 1, received: 0 }, and a late successful discover givesConflictInitResponseId(1, 0)(same as openai/codex#57631). Once the timeout fallback sendsinitializethe session is legacy, so the fix is to skip any reply to the probe id from then on, including a late discover success. If you'd like to take it @arohou please go ahead and open the PR.