Uh oh!
There was an error while loading. Please reload this page.
Fix/issue 817 idle timeout log level - #824
Conversation
Idle keep-alive timeout is normal zombie-session cleanup, not a transport failure. Route it through a dedicated WorkerQuitReason::IdleTimeout variant. Log it at debug level instead of treating it as a fatal error. Remove the unused LocalSessionWorkerError::KeepAliveTimeout variant. Closesmodelcontextprotocol#817
Swallow SessionServiceTerminated in close_session when the worker has already exited. This prevents a spurious ERROR log during the post-exit cleanup path in spawn_session_worker.
| #[error("keep alive timeout after {}ms", _0.as_millis())] | ||
| KeepAliveTimeout(Duration), |
There was a problem hiding this comment.
The removed LocalSessionWorkerError::KeepAliveTimeout variant was not part of the public API.
I think it's reachable via fully pub module chain:rmcp::transport::streamable_http_server::session::local::LocalSessionWorkerError::KeepAliveTimeout
Could we keep the variant with #[deprecated] to avoid a breaking change?
| TransportClosed, | ||
| #[error("Handler terminated")] | ||
| HandlerTerminated, | ||
| #[error("Worker idle timeout ({}ms)", _0.as_millis())] |
There was a problem hiding this comment.
| #[error("Worker idle timeout ({}ms)", _0.as_millis())] | |
| #[error("Worker idle timeout after {}ms", _0.as_millis())] |
| let error_events: Vec<_> = captured | ||
| .iter() | ||
| .filter(|e| e.level == tracing::Level::ERROR) |
There was a problem hiding this comment.
How about we also filter errors by target? Any unrelated subsystem that logs at ERROR would flake this test.
There was a problem hiding this comment.
Added target field and scoped both filters to starts_with("rmcp")
- deprecate KeepAliveTimeout - harden tests
DaleSeo
left a comment
There was a problem hiding this comment.
Thanks for addressing my feedback, @lutz-grex!
Uh oh!
There was an error while loading. Please reload this page.
Brings in upstream rmcp v1.7.0: - fix(rmcp): flatten Resource variant of PromptMessageContent (modelcontextprotocol#843) - fix: reply -32700 on stdio parse errors instead of closing (modelcontextprotocol#833) -- JsonRpcError.id is now Option<RequestId> per MCP spec - chore(rmcp): remove dependency on chrono default features (modelcontextprotocol#829) - fix: idle-timeout log level demoted to debug (modelcontextprotocol#824) - feat: task-based stdio examples (modelcontextprotocol#839) - chore(deps): askama 0.15 -> 0.16 (modelcontextprotocol#830) - ci: extend semver check to all features except local (modelcontextprotocol#832) Conflict resolution: - crates/rmcp/CHANGELOG.md: kept fork's bare-boolean Unreleased entry, inserted upstream's 1.7.0 release section beneath it - crates/rmcp/Cargo.toml: kept fork's chrono 0.4.44 over upstream's 0.4.38 pin, but adopted upstream's default-features = false + features = ["serde", "now"] from modelcontextprotocol#829 -- both intents preserved - crates/rmcp/src/service.rs: kept fork's METHOD_NOT_FOUND demotion to debug (ab4ccdb) and applied upstream's JsonRpcMessage::error signature change to Some(id) per modelcontextprotocol#833 Workspace bumped to 1.7.0 by upstream's release-plz commit; fork crates rmcp + rmcp-macros track that automatically via workspace = true. anthropic-ext, JsonAndArtifact wrapper, bare-bool schema normalisation, channel permission relay, and the rest of the fork-only surface are unchanged. cargo check + cargo test pass with the full anthropic-ext + server feature set; test_message_schema absorbs the JsonRpcError.id Option change cleanly.
Idle keep-alive timeout is normal zombie-session cleanup, not a transport failure. This PR stops it from producing
ERROR-level log lines that are indistinguishable from real transport fatals.Motivation and Context
When
LocalSessionWorkerhits its configured keep-alive timeout (default 5 min), it returnsWorkerQuitReason::Fatal, which the transport worker logs attracing::error!. TheSessionConfig::keep_alivedocstring explicitlyframes this as a safety net for silently-dropped HTTP connections — normal lifecycle cleanup, not an error condition.
This causes every idle reap to emit:
Operators who wire ERROR-level alerts get paged on something that is normal by design. Downstream consumers cannot filter idle reaps without also silencing real transport fatals.
Additionally, the post-exit cleanup path in
close_sessioncould fail withSessionServiceTerminatedwhen the worker had already exited due to idle timeout, producing a second spurious error.Closes#817
How Has This Been Tested?
test_keep_alive_timeout_does_not_emit_error_log) that spins up a Streamable HTTP server with a 200ms keep-alive, connects a client, waits for idle reap, and asserts: no ERROR-level logs areemitted, and a DEBUG log with
IdleTimeoutis present.test_explicit_close_on_live_session_succeeds) that verifiesclose_sessionon a still-alive worker succeeds without error.cargo test).Breaking Changes
None.
WorkerQuitReasonis#[non_exhaustive], so the newIdleTimeoutvariant is additive. The removedLocalSessionWorkerError::KeepAliveTimeoutvariant was not part of the public API.Types of changes
Checklist
Additional context
This implements Option A from #817: a dedicated
WorkerQuitReason::IdleTimeout(Duration)variant that is logged atdebuglevel alongside the other expected-exit arms (Cancelled,TransportClosed,HandlerTerminated). Truetransport failures continue to flow through
Fataland keep their ERROR severity.Changes across two commits:
d41d3c8— AddWorkerQuitReason::IdleTimeout, return it from the keep-alive arm, log at debug. Remove unusedKeepAliveTimeouterror variant.2463369— SwallowSessionServiceTerminatedinclose_sessionwhen the worker has already exited, preventing a spurious error during post-exit cleanup.