From bdf060f9982fd6a32d26a1b01c8ca6fa11dbd89b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ate=C5=9F=20G=C3=B6ral?= Date: Sat, 7 Nov 2026 15:08:43 -0500 Subject: [PATCH] fix: keep logging levels per session --- lib/mcp/server.rb | 14 ++- lib/mcp/server/transports/stdio_transport.rb | 12 ++ .../transports/streamable_http_transport.rb | 14 +++ .../stdio_notification_integration_test.rb | 65 ++++++++++ .../streamable_http_logging_test.rb | 116 ++++++++++++++++++ test/mcp/server_notification_test.rb | 78 +++++++++++- 6 files changed, 294 insertions(+), 5 deletions(-) create mode 100644 test/mcp/server/transports/streamable_http_logging_test.rb diff --git a/lib/mcp/server.rb b/lib/mcp/server.rb index 7ae234b7..126c0c68 100644 --- a/lib/mcp/server.rb +++ b/lib/mcp/server.rb @@ -447,6 +447,13 @@ def notify_resources_list_changed # Use stderr or OpenTelemetry instead. def notify_log_message(data:, level:, logger: nil) return unless @transport + + if @transport.respond_to?(:logging_sessions) && (sessions = @transport.logging_sessions) + sessions.each do |session| + session.notify_log_message(data: data, level: level, logger: logger) + end + return + end return unless logging_message_notification&.should_notify?(level) params = { "data" => data, "level" => level } @@ -1382,8 +1389,11 @@ def configure_logging_level(request, session: nil) raise RequestHandlerError.new("Invalid log level #{request[:level]}", request, error_type: :invalid_params) end - session&.configure_logging(logging_message_notification) - @logging_message_notification = logging_message_notification + if session + session.configure_logging(logging_message_notification) + else + @logging_message_notification = logging_message_notification + end {} end diff --git a/lib/mcp/server/transports/stdio_transport.rb b/lib/mcp/server/transports/stdio_transport.rb index 911813b3..32dc5c9f 100644 --- a/lib/mcp/server/transports/stdio_transport.rb +++ b/lib/mcp/server/transports/stdio_transport.rb @@ -96,6 +96,18 @@ def internal_error_response(parsed) response end + # Sessions a server-wide log broadcast is offered to, each applying its own level or the server default. + # Public only so that `Server#notify_log_message` can call it. Custom transports may implement this hook; + # returning `nil` keeps the server-wide filter. + # + # @api private + # @return [Array, nil] + def logging_sessions + return unless @session + + @session.era == :legacy ? [@session] : [] + end + def send_notification(method, params = nil) notification = { jsonrpc: "2.0", diff --git a/lib/mcp/server/transports/streamable_http_transport.rb b/lib/mcp/server/transports/streamable_http_transport.rb index 86e442a0..a669629d 100644 --- a/lib/mcp/server/transports/streamable_http_transport.rb +++ b/lib/mcp/server/transports/streamable_http_transport.rb @@ -509,6 +509,20 @@ def close end end + # Sessions a server-wide log broadcast is offered to, each applying its own level or the server default. + # Public only so that `Server#notify_log_message` can call it. Custom transports may implement this hook; + # returning `nil` keeps the server-wide filter. + # + # @api private + # @return [Array] + def logging_sessions + @mutex.synchronize do + @sessions.values.filter_map do |session| + session[:server_session] if session[:get_sse_stream] + end + end + end + def send_notification(method, params = nil, session_id: nil, related_request_id: nil) # `subscriptions/listen` streams (SEP-2575) receive matching change notifications regardless of the delivery below: # a resource updated by one session's tool call changed globally, so modern subscribers hear about it too. diff --git a/test/mcp/server/transports/stdio_notification_integration_test.rb b/test/mcp/server/transports/stdio_notification_integration_test.rb index f0d1963f..05c75134 100644 --- a/test/mcp/server/transports/stdio_notification_integration_test.rb +++ b/test/mcp/server/transports/stdio_notification_integration_test.rb @@ -6,6 +6,8 @@ module MCP class Server module Transports class StdioNotificationIntegrationTest < ActiveSupport::TestCase + include InitializeParamsTestHelper + class MockIO attr_reader :output @@ -259,6 +261,69 @@ def puts(message) assert_equal Methods::NOTIFICATIONS_MESSAGE, third_notification["method"] assert_equal({ "data" => { "error" => "Connection Failed" }, "level" => "error" }, third_notification["params"]) end + + test "server log messages honor the stdio client's level instead of the application default" do + default_logging = LoggingMessageNotification.new(level: "critical") + @server.logging_message_notification = default_logging + server = @server + @server.define_tool(name: "log_messages") do + server.notify_log_message(data: "debug log", level: "debug") + server.notify_log_message(data: "broadcast log", level: "info") + Tool::Response.new([{ type: "text", text: "ok" }]) + end + requests = [ + { jsonrpc: "2.0", id: 1, method: "initialize", params: initialize_params(protocolVersion: "2025-11-25") }, + { jsonrpc: "2.0", method: "notifications/initialized" }, + { jsonrpc: "2.0", id: 2, method: "logging/setLevel", params: { level: "info" } }, + { jsonrpc: "2.0", id: 3, method: "tools/call", params: { name: "log_messages", arguments: {} } }, + ] + frames = requests.map { |request| "#{request.to_json}\n" } + @mock_stdin.stubs(:gets).returns(*frames, nil) + + @transport.open + + messages = @mock_stdout.output.map { |message| JSON.parse(message) } + assert_equal({}, messages.find { |message| message["id"] == 2 }["result"]) + assert_equal "ok", messages.find { |message| message["id"] == 3 }["result"]["content"].first["text"] + logs = messages.select { |message| message["method"] == Methods::NOTIFICATIONS_MESSAGE } + assert_equal 1, logs.size + assert_equal "broadcast log", logs.first["params"]["data"] + assert_same default_logging, @server.logging_message_notification + end + + test "modern stdio logs stay request-scoped even with an application default" do + @server.logging_message_notification = LoggingMessageNotification.new(level: "debug") + server = @server + @server.define_tool(name: "log_messages") do |server_context:| + server.notify_log_message(data: "broadcast log", level: "info") + server_context.notify_log_message(data: "request log", level: "error") + Tool::Response.new([{ type: "text", text: "ok" }]) + end + meta = { + "io.modelcontextprotocol/protocolVersion": "2026-07-28", + "io.modelcontextprotocol/clientInfo": { name: "modern_client", version: "1.0" }, + "io.modelcontextprotocol/clientCapabilities": {}, + } + requests = [ + { jsonrpc: "2.0", id: 1, method: "server/discover" }, + { jsonrpc: "2.0", id: 2, method: "tools/call", params: { name: "log_messages", arguments: {}, _meta: meta } }, + { + jsonrpc: "2.0", id: 3, method: "tools/call", params: { + name: "log_messages", arguments: {}, _meta: meta.merge("io.modelcontextprotocol/logLevel": "error"), + }, + }, + ] + frames = requests.map { |request| "#{request.to_json}\n" } + @mock_stdin.stubs(:gets).returns(*frames, nil) + + @transport.open + + messages = @mock_stdout.output.map { |message| JSON.parse(message) } + assert_equal "ok", messages.find { |message| message["id"] == 2 }["result"]["content"].first["text"] + assert_equal "ok", messages.find { |message| message["id"] == 3 }["result"]["content"].first["text"] + logs = messages.select { |message| message["method"] == Methods::NOTIFICATIONS_MESSAGE } + assert_equal ["request log"], logs.map { |message| message["params"]["data"] } + end end end end diff --git a/test/mcp/server/transports/streamable_http_logging_test.rb b/test/mcp/server/transports/streamable_http_logging_test.rb new file mode 100644 index 00000000..b0d4775c --- /dev/null +++ b/test/mcp/server/transports/streamable_http_logging_test.rb @@ -0,0 +1,116 @@ +# frozen_string_literal: true + +require "test_helper" +require "rack/mock" + +module MCP + class Server + module Transports + class StreamableHTTPLoggingTest < ActiveSupport::TestCase + include InitializeParamsTestHelper + + setup do + @server = Server.new(name: "test_server") + @transport = StreamableHTTPTransport.new(@server) + @transport.stubs(:start_keepalive_thread) + end + + teardown do + @transport.close + end + + test "broadcasts use each session's level before the application default" do + default_logging = LoggingMessageNotification.new(level: "warning") + @server.logging_message_notification = default_logging + debug_session, debug_stream = open_session + error_session, error_stream = open_session + _, default_stream = open_session + + set_level(debug_session, "debug") + set_level(error_session, "error") + _, future_stream = open_session + + ["debug", "info", "warning", "error"].each do |level| + @server.notify_log_message(data: { message: level }, level: level, logger: "ExampleLogger") + end + + assert_equal ["debug", "info", "warning", "error"], log_levels(debug_stream) + assert_equal ["error"], log_levels(error_stream) + assert_equal ["warning", "error"], log_levels(default_stream) + assert_equal ["warning", "error"], log_levels(future_stream) + assert_equal "ExampleLogger", messages(debug_stream).first["params"]["logger"] + assert_same default_logging, @server.logging_message_notification + end + + test "one session setting a level does not enable broadcasts to other sessions" do + session, stream = open_session + _, other_stream = open_session + set_level(session, "info") + _, future_stream = open_session + + @server.notify_log_message(data: "debug detail", level: "debug") + @server.notify_log_message(data: "info detail", level: "info") + + assert_equal ["info"], log_levels(stream) + assert_empty messages(other_stream) + assert_empty messages(future_stream) + assert_nil @server.logging_message_notification + end + + private + + def request(method, payload: nil, session_id: nil) + env = Rack::MockRequest.env_for("http://localhost/", method: method) + env["HTTP_ACCEPT"] = "application/json, text/event-stream" + env["HTTP_MCP_PROTOCOL_VERSION"] = "2025-11-25" + env["HTTP_MCP_SESSION_ID"] = session_id if session_id + if payload + env["CONTENT_TYPE"] = "application/json" + env["rack.input"] = StringIO.new(payload.to_json) + end + @transport.call(env) + end + + def open_session + status, headers, body = request("POST", payload: { + jsonrpc: "2.0", id: 1, method: "initialize", + params: initialize_params(protocolVersion: "2025-11-25"), + }) + assert_equal 200, status + assert_equal({}, JSON.parse(body.join).dig("result", "capabilities", "logging")) + session_id = headers.fetch("mcp-session-id") + status, = request("POST", session_id: session_id, payload: { + jsonrpc: "2.0", method: "notifications/initialized", + }) + assert_equal 202, status + + status, headers, body = request("GET", session_id: session_id) + assert_equal 200, status + assert_equal "text/event-stream", headers["content-type"] + stream = StringIO.new + body.call(stream) + [session_id, stream] + end + + def set_level(session_id, level) + status, headers, body = request("POST", session_id: session_id, payload: { + jsonrpc: "2.0", id: 2, method: "logging/setLevel", params: { level: level }, + }) + assert_equal 200, status + assert_equal "text/event-stream", headers["content-type"] + stream = StringIO.new + body.call(stream) + assert_equal({}, messages(stream).last["result"]) + end + + def messages(stream) + stream.string.scan(/^data: (.+)$/).flatten.map { |json| JSON.parse(json) } + end + + def log_levels(stream) + messages(stream).map { |message| message["params"]["level"] } + end + end + end + end +end diff --git a/test/mcp/server_notification_test.rb b/test/mcp/server_notification_test.rb index c1f32fcf..ec13b204 100644 --- a/test/mcp/server_notification_test.rb +++ b/test/mcp/server_notification_test.rb @@ -9,6 +9,7 @@ class ServerNotificationTest < ActiveSupport::TestCase class MockTransport < Transport attr_reader :notifications + attr_accessor :logging_sessions def initialize(server) super @@ -302,22 +303,93 @@ def send_notification(method, params = nil) assert_equal Methods::NOTIFICATIONS_MESSAGE, notifications[3][:method] end + test "logging/setLevel does not enable logs in other existing or future sessions" do + session = ServerSession.new(server: @server, transport: @mock_transport) + other_session = ServerSession.new(server: @server, transport: @mock_transport) + @server.define_tool(name: "log_debug") do |server_context:| + server_context.notify_log_message(data: "debug detail", level: "debug") + Tool::Response.new([{ type: "text", text: "ok" }]) + end + + response = session.handle( + { jsonrpc: "2.0", id: 1, method: "logging/setLevel", params: { level: "debug" } }, + ) + assert_equal({}, response[:result]) + future_session = ServerSession.new(server: @server, transport: @mock_transport) + + [other_session, future_session].each do |unconfigured_session| + response = unconfigured_session.handle( + { jsonrpc: "2.0", id: 2, method: "tools/call", params: { name: "log_debug", arguments: {} } }, + ) + assert_equal "ok", response[:result][:content].first[:text] + end + + assert_empty @mock_transport.notifications + assert_nil @server.logging_message_notification + + response = session.handle( + { jsonrpc: "2.0", id: 3, method: "tools/call", params: { name: "log_debug", arguments: {} } }, + ) + assert_equal "ok", response[:result][:content].first[:text] + assert_equal 1, @mock_transport.notifications.size + assert_equal "debug detail", @mock_transport.notifications.first[:params]["data"] + end + + test "logging/setLevel does not change an application-configured server-wide default" do + default_logging = LoggingMessageNotification.new(level: "error") + @server.logging_message_notification = default_logging + session = ServerSession.new(server: @server, transport: @mock_transport) + other_session = ServerSession.new(server: @server, transport: @mock_transport) + + response = session.handle( + { jsonrpc: "2.0", id: 1, method: "logging/setLevel", params: { level: "debug" } }, + ) + assert_equal({}, response[:result]) + future_session = ServerSession.new(server: @server, transport: @mock_transport) + + [other_session, future_session].each do |unconfigured_session| + unconfigured_session.notify_log_message(data: "info detail", level: "info") + unconfigured_session.notify_log_message(data: "error detail", level: "error") + end + @server.notify_log_message(data: "broadcast info", level: "info") + @server.notify_log_message(data: "broadcast error", level: "error") + session.notify_log_message(data: "session debug", level: "debug") + + assert_equal ["error detail", "error detail", "broadcast error", "session debug"], + @mock_transport.notifications.map { |notification| notification[:params]["data"] } + assert_same default_logging, @server.logging_message_notification + end + test "server.notify_log_message works after logging/setLevel via session" do session = ServerSession.new(server: @server, transport: @mock_transport) + @mock_transport.logging_sessions = [session] # Client sends logging/setLevel through session. - @server.handle( + response = @server.handle( { jsonrpc: "2.0", id: 1, method: "logging/setLevel", params: { level: "info" } }, session: session, ) + assert_equal({}, response[:result]) - # Server-level broadcast should still work because logging level - # is stored on both the session and the server. @server.notify_log_message(data: "broadcast log", level: "info") log_notifications = @mock_transport.notifications.select { |n| n[:method] == Methods::NOTIFICATIONS_MESSAGE } assert_equal 1, log_notifications.size assert_equal "broadcast log", log_notifications.first[:params]["data"] end + + test "logging/setLevel without a session configures server-wide broadcasts" do + response = @server.handle( + { jsonrpc: "2.0", id: 1, method: "logging/setLevel", params: { level: "info" } }, + ) + assert_equal({}, response[:result]) + + @server.notify_log_message(data: "debug log", level: "debug") + @server.notify_log_message(data: "broadcast log", level: "info") + + assert_equal 1, @mock_transport.notifications.size + assert_equal Methods::NOTIFICATIONS_MESSAGE, @mock_transport.notifications.first[:method] + assert_equal "broadcast log", @mock_transport.notifications.first[:params]["data"] + end end end