Pre-prod: ac.inference.sh MCP server transport drops repeatedly (14x) — reconnects but unstable

[Al629176]

Summary

The ac.inference.sh/mcp MCP server connects successfully on boot (25 tools registered) but drops its transport connection repeatedly throughout the session, triggering reconnect cycles. 14 transport drop events observed.

Log evidence (pre-prod, 2026-08-20)

16:03:06 INF [mcp-registry] boot: connected server_id=00bbad23-4dab-443e-9f0b-ae73af1d6bb3
qualified=ac.inference.sh/mcp tools=25

18:41:12 WRN [mcp-supervisor] server_id=00bbad23-4dab-443e-9f0b-ae73af1d6mb3
qualified=ac.inference.sh/mcp transport dropped; reconnecting
[repeats 14x across session]

Unlike the GitHub MCP issue in staging (#5600), this server connects — the transport drops under load or after idle periods.

Impact

During a transport drop, any agent tool call routed to ac.inference.sh/mcp fails until the reconnect completes. With 14 drops in one session, this is a persistent reliability issue for inference tools.

Fix direction

• Investigate whether ac.inference.sh/mcp has a server-side idle timeout that drops the connection.
• Add a keepalive ping on the MCP transport layer to prevent idle drops.
• Confirm the MCP supervisor reconnect succeeds quickly and tools are re-registered without requiring a full app restart.

[M3gA-Mind]

How to fix this

Root cause: the supervisor never measures what it reports. probe_alive deliberately collapses three different conditions — missing entry, transport error, and probe timeout — into a single false, and the supervisor turns that one bool into a specific causal claim ("the transport dropped") and an unconditional teardown of the session. A server that is alive but answers slower than the 8-second probe window is therefore disconnected by the supervisor itself, and the "reconnect" that follows is repairing damage the supervisor caused. Nothing in these logs distinguishes that from a real drop.

Where:

• vendor/tinymcp/crates/tinymcp/src/registry/connections/types.rs:319-323 — the doc comment makes the collapse explicit: "A missing entry, a transport error, and a timeout all report false: each means 'not usable, reconnect', and distinguishing them would give a caller a choice it has no different response to." That premise is the bug — there is a different correct response to a timeout.
• …/connections/types.rs:325-341 — probe_alive; :333 probe found a broken transport and :337 probe timed out are both tracing::debug!.
• vendor/tinymcp/crates/tinymcp/src/registry/supervisor/types.rs:112 — the probe call; :119-122 the warn! asserting the cause; :124 connections.disconnect(&server_id) on the first negative probe, with no consecutive-failure requirement.
• …/supervisor/types.rs:25-26 — tick_interval: 60s, probe_timeout: 8s.
• …/supervisor/types.rs:155 — a failures counter exists but is only used on the connect path; the probe path has no equivalent.

The discriminating lines are debug; the line that asserts a cause is warn. So a field log at default level structurally cannot diagnose this — which is why 14 identical warnings tell you nothing about why.

Why a timeout is the better explanation here: the probe is a full tools/list round trip (tinymcp has no ping), against a server advertising 25 tools. From the timestamps in the report — boot 16:03:06, still dropping at 18:41:12 — the session ran ≥2h38m, i.e. ≥158 ticks, and produced 14 drops: a ~9% probe-failure rate that always recovers. That is the shape of an occasionally-exceeded 8s timeout, not of a transport dying 14 times and resurrecting 14 times.

The change, in three parts:

1. Replace the bool with an outcome — enum ProbeOutcome { Alive, Missing, Broken(String), TimedOut } returned from probe_alive. Update the doc comment, since its stated rationale no longer holds.
2. Act on the distinction at supervisor/types.rs:112-124. Missing and Broken keep today's behaviour: disconnect and reconnect immediately. TimedOut increments a per-server consecutive-timeout counter on the supervisor and only disconnects once it reaches a small threshold (2 or 3); any Alive resets it. The counter must live on Supervisor beside backoff, not in Connections — disconnect() clears the failures map at connections/types.rs:346, so a counter kept there would erase itself.
3. Make the message report what was observed: "probe did not answer within {probe_timeout:?}" with the outcome as a field, rather than "the transport dropped". Keep it at warn, and let the reason ride on it instead of sitting in debug.

How to prove it: …/supervisor/test.rs already has the fixture shape — serve_working_server() plus a_dropped_transport_is_noticed_and_reconnected at :473. Add a serve_slow_server(delay) that sleeps past the probe window before answering tools/list, and a SupervisorConfig with a short probe_timeout:

• one slow probe, then a fast one → assert connections.connected_count().await == 1 and no reconnect occurred. This fails today: the single timeout disconnects, so the count drops to 0 and the session is rebuilt.
• N consecutive slow probes → assert the disconnect does eventually happen, so a genuinely wedged server is still recovered.
• a transport error → assert disconnect and reconnect still happen on the first observation, i.e. no regression to the case the supervisor was built for.

Risk / blast radius: confined to the supervisor and probe_alive; every caller of probe_alive needs updating for the new return type. The real trade-off is recovery latency — gating teardown on N consecutive timeouts delays recovery from a genuinely dead-but-silent transport by up to N×60s, during which a user's tool call hits a stale session instead of a reconnecting one. Keeping immediate teardown for Broken/Missing and applying the threshold only to TimedOut confines that cost to the case where the connection is probably fine. Changing the probe's meaning also affects any health surface that reads it.

Not covered by this:

• The issue's "add a keepalive ping on the MCP transport layer" would not help. The supervisor already performs a round trip every 60s, which is keepalive traffic; the problem is the reaction to a slow answer, not an absence of traffic. A real ping would still be worth adding so the probe is cheaper than listing 25 tools, but it is a separate change and does not address the misreport.
• Whether ac.inference.sh/mcp has a server-side idle timeout. That cannot be answered from this repo — see below.
• The third bullet (tools re-registered without a restart). The reconnect path does log tools=<n> at supervisor/types.rs:144, so it is readable from the same logs, but I did not verify re-registration semantics.

MAINTAINER CHECK — needed to confirm which of the three outcomes actually fired in pre-prod. Nothing in the repo can answer it, because the discriminator is debug-level and the reported logs are INF/WRN. I need one of:

1. a pre-prod run with RUST_LOG=tinymcp::registry::connections=debug (or the whole tinymcp target at debug), then the lines immediately preceding each the transport dropped; reconnecting — probe timed out means self-inflicted churn and confirms the diagnosis above; probe found a broken transport: <err> means a genuine drop and the fix is elsewhere; or
2. the idle/read timeout policy on the ac.inference.sh deployment, and whether it closes idle HTTP MCP sessions — a third-party endpoint I cannot reach.

APP CHECK — mechanism only, not this server. ac.inference.sh/mcp is not installed on this machine: all four mcp_servers tables under ~/.openhuman/users/*/workspace/mcp_clients/mcp_clients.db are empty, so it cannot be reproduced locally as-is. The supervisor path is server-agnostic, though, so the mechanism can be exercised with any HTTP MCP server: install one via Settings → MCP, launch with RUST_LOG=tinymcp=debug, leave it idle past a few 60-second ticks, and watch for probe timed out in the log. Confirms if a probe timed out line appears with the server still functional afterwards; refutes if every the transport dropped warn is preceded by probe found a broken transport. This validates the misreport, not ac.inference.sh's specific behaviour — only the maintainer check settles that.

Confidence: high on the mechanism and on the message being unearned — both are read directly off the code, and the collapse is documented as intentional. Low on the claim that these particular 14 drops were timeouts rather than real drops: that is inference from the rate and the recovery pattern, and it is exactly what the maintainer check would settle. I have not asserted it as established.

— fleet research, verified against main @ e1c332b

[M3gA-Mind]

Fix raised: tinyhumansai/tinymcp#5 — fix(supervisor): report what a probe observed instead of asserting a drop. All CI green, MERGEABLE.

The MCP client left this repo in 050b2d687 (extracted to tinyhumansai/tinymcp), so the fix lands there, not here. It makes the probe report what it actually measured — timeout vs transport error, with observed latency — instead of asserting "transport dropped", and reconciles the probe deadline with the transport timeout that install-time validation already blessed.

No closing keyword on the PR (cross-repo). Close this issue by hand once PR 5 merges and the tinymcp submodule is bumped here.

— fleet, verified against main @ e1c332b

[M3gA-Mind]

Fixed and now delivered to openhuman.

tinymcp#5 — fix(supervisor): report what a probe observed instead of asserting a drop — reached this repo when #5772 merged (2b716ed32) and moved the vendor/tinymcp pin to 5909bd1f7.

Verified by ancestry, not by version number:

compare/<tinymcp#5 merge sha>...5909bd1f7  ->  status=ahead, behind_by=0

What it changes for this issue: the supervisor now reports what the probe actually observed — timeout versus transport error, with the measured latency — instead of asserting "transport dropped" as a cause it never measured. That was the core of this report: 14 drops attributed to a cause nobody had established.

Note #5772 also carried the caller adaptation: tinymcp#5 changed probe_alive from bool to a #[non_exhaustive] enum ProbeOutcome { Alive, Missing, Broken, TimedOut } — deliberately, since false had collapsed three distinct failures into one — and openhuman's three call sites in tests/mcp_registry_e2e.rs were updated to match.

Closing by hand because the fixing PR lives in another repository and could not carry a closing keyword.