diff --git a/CHANGELOG.md b/CHANGELOG.md index 6c0c47af..19fe17c3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/), ### Added +- MCP logging capability declaration and `logging/setLevel` request handler that allows MCP clients to control structured log output according to the MCP protocol specification (2025-06-18) ([#340](https://github.com/microsoft/wassette/pull/340)) - `rust-toolchain.toml` file specifying Rust 1.90 as the stable toolchain version, ensuring consistent Rust version across development environments and CI/CD pipelines - AI agent development guides (`AGENTS.md` and `Claude.md`) that consolidate development guidelines from `.github/instructions/` into accessible documentation for AI agents working on the project - Comprehensive installation guide page consolidating all installation methods (one-liner script, Homebrew, Nix, WinGet) organized by platform (Linux, macOS, Windows) with verification steps and troubleshooting sections diff --git a/Cargo.lock b/Cargo.lock index 520e9c57..fa911d3c 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -4980,6 +4980,7 @@ dependencies = [ "axum", "built", "bytes", + "chrono", "clap", "etcetera", "figment", diff --git a/Cargo.toml b/Cargo.toml index 9098a425..8d2a229c 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -13,6 +13,7 @@ license-file = "LICENSE" [workspace.dependencies] anyhow = "1.0" +chrono = "0.4" component2json = { path = "crates/component2json" } etcetera = "0.10" futures = "0.3" @@ -45,6 +46,7 @@ wasmtime-wasi-config = "36" [dependencies] anyhow = { workspace = true } axum = "0.8" +chrono = { workspace = true } clap = { version = "4.5", features = ["derive"] } etcetera = { workspace = true } figment = { version = "0.10", features = ["env", "toml"] } diff --git a/docs/SUMMARY.md b/docs/SUMMARY.md index 1c04171b..e124974c 100644 --- a/docs/SUMMARY.md +++ b/docs/SUMMARY.md @@ -18,6 +18,7 @@ - [CLI](./reference/cli.md) - [Permissions](./reference/permissions.md) +- [MCP Logging](./mcp-logging.md) # Design & Architecture diff --git a/docs/mcp-logging.md b/docs/mcp-logging.md new file mode 100644 index 00000000..6db54b49 --- /dev/null +++ b/docs/mcp-logging.md @@ -0,0 +1,179 @@ +# MCP Logging + +Wassette implements the Model Context Protocol (MCP) logging specification, allowing MCP clients to receive structured log messages from the server. + +## Overview + +The MCP logging feature provides: + +- **Structured log output**: Log messages are sent as JSON-RPC notifications to MCP clients +- **Level filtering**: Clients can set a minimum log level to control verbosity +- **Syslog severity levels**: Supports all standard syslog levels (Emergency, Alert, Critical, Error, Warning, Notice, Info, Debug) +- **Automatic forwarding**: Internal tracing logs are automatically converted to MCP notifications + +## Logging Capability + +Wassette declares the `logging` capability in its server capabilities: + +```json +{ + "capabilities": { + "logging": {}, + "tools": { "listChanged": true } + } +} +``` + +## Setting Log Level + +Clients can control log verbosity using the `logging/setLevel` request: + +```json +{ + "jsonrpc": "2.0", + "method": "logging/setLevel", + "params": { + "level": "info" + }, + "id": 2 +} +``` + +**Supported levels** (in order of decreasing severity): +- `emergency` - System is unusable +- `alert` - Action must be taken immediately +- `critical` - Critical conditions +- `error` - Error conditions +- `warning` - Warning conditions +- `notice` - Normal but significant events +- `info` - General informational messages +- `debug` - Detailed debugging information + +## Log Message Notifications + +After setting a log level, the server sends log messages as `notifications/message` notifications: + +```json +{ + "jsonrpc": "2.0", + "method": "notifications/message", + "params": { + "level": "info", + "logger": "wassette", + "data": { + "message": "Component loaded successfully", + "target": "wassette::lifecycle", + "timestamp": "2025-01-09T12:34:56.789Z" + } + } +} +``` + +## Log Level Filtering + +Only log messages at or above the configured minimum level are sent to clients. For example, if the level is set to `info`: + +- ✅ `emergency`, `alert`, `critical`, `error`, `warning`, `notice`, and `info` messages are sent +- ❌ `debug` messages are filtered out + +## Implementation Details + +### Architecture + +Wassette uses a custom `tracing` subscriber layer (`McpLoggingLayer`) that: + +1. Intercepts log events from the `tracing` framework +2. Converts them to MCP `LoggingMessageNotificationParam` structures +3. Filters based on the client-configured minimum level +4. Sends notifications to connected MCP clients + +### Level Mapping + +Tracing levels are mapped to MCP levels as follows: + +| Tracing Level | MCP Level | +|---------------|-----------| +| `ERROR` | `error` | +| `WARN` | `warning` | +| `INFO` | `info` | +| `DEBUG` | `debug` | +| `TRACE` | `debug` | + +### Message Structure + +Each log notification includes: + +- **level**: The log severity level +- **logger**: The source module or component (optional) +- **data**: A JSON object containing: + - `message`: The log message text + - `target`: The tracing target (typically module path) + - `timestamp`: RFC3339-formatted timestamp + +## Example Usage + +### With MCP Inspector + +```bash +# Start Wassette server +cargo run -- serve --sse + +# In another terminal, connect with MCP inspector +npx @modelcontextprotocol/inspector --cli http://127.0.0.1:9001/sse + +# Set log level to info +# (Use inspector UI to send logging/setLevel request) +``` + +### Programmatic Example + +```javascript +// Connect to Wassette MCP server +const client = new MCPClient(transport); + +// Initialize connection +await client.initialize({ + protocolVersion: "2024-11-05", + clientInfo: { name: "my-client", version: "1.0.0" } +}); + +// Set log level +await client.request({ + method: "logging/setLevel", + params: { level: "info" } +}); + +// Listen for log notifications +client.on("notifications/message", (notification) => { + const { level, logger, data } = notification.params; + console.log(`[${level}] ${logger}: ${data.message}`); +}); +``` + +## Security Considerations + +- Log messages should not contain sensitive information (credentials, tokens, etc.) +- The logging layer automatically filters out logs when no client has set a log level +- Each client can set their own log level independently + +## Troubleshooting + +### No log messages received + +1. Verify the logging capability is declared in server capabilities +2. Ensure you've sent a `logging/setLevel` request +3. Check that the log level is appropriate (e.g., `debug` for maximum verbosity) +4. Verify the MCP client is listening for `notifications/message` + +### Too many/too few log messages + +Adjust the log level: +- Use `debug` for detailed troubleshooting +- Use `info` for normal operation +- Use `warning` or `error` for production monitoring + +## Reference + +- [MCP Logging Specification](https://modelcontextprotocol.io/specification/2025-06-18/server/utilities/logging) +- [Tracing Documentation](https://docs.rs/tracing/latest/tracing/) +- [Syslog Severity Levels (RFC 5424)](https://datatracker.ietf.org/doc/html/rfc5424#section-6.2.1) diff --git a/src/main.rs b/src/main.rs index 81dbc4de..8f4c68a0 100644 --- a/src/main.rs +++ b/src/main.rs @@ -23,7 +23,8 @@ use mcp_server::{ }; use rmcp::model::{ CallToolRequestParam, CallToolResult, ErrorData, ListPromptsResult, ListResourcesResult, - ListToolsResult, PaginatedRequestParam, ServerCapabilities, ServerInfo, ToolsCapability, + ListToolsResult, LoggingLevel, PaginatedRequestParam, ServerCapabilities, ServerInfo, + SetLevelRequestParam, ToolsCapability, }; use rmcp::service::{serve_server, RequestContext, RoleServer}; use rmcp::transport::streamable_http_server::session::local::LocalSessionManager; @@ -37,6 +38,7 @@ use tracing_subscriber::util::SubscriberInitExt as _; mod commands; mod config; mod format; +mod mcp_logging; use commands::{ Cli, Commands, ComponentCommands, GrantPermissionCommands, PermissionCommands, PolicyCommands, @@ -194,6 +196,7 @@ const BIND_ADDRESS: &str = "127.0.0.1:9001"; pub struct McpServer { lifecycle_manager: LifecycleManager, peer: Arc>>>, + log_level: Arc>>, } /// Handle CLI tool commands by creating appropriate tool call requests @@ -301,6 +304,7 @@ impl McpServer { Self { lifecycle_manager, peer: Arc::new(Mutex::new(None)), + log_level: Arc::new(Mutex::new(None)), } } @@ -326,6 +330,7 @@ impl ServerHandler for McpServer { tools: Some(ToolsCapability { list_changed: Some(true), }), + logging: Some(serde_json::Map::new()), ..Default::default() }, instructions: Some( @@ -421,6 +426,22 @@ Key points: } }) } + + #[allow(clippy::manual_async_fn)] + fn set_level( + &self, + params: SetLevelRequestParam, + _ctx: RequestContext, + ) -> impl Future> + Send + '_ { + async move { + // Store the requested log level + let mut log_level = self.log_level.lock().unwrap(); + *log_level = Some(params.level); + + tracing::info!("MCP logging level set to: {:?}", params.level); + Ok(()) + } + } } /// Formats build information similar to agentgateway's version output @@ -482,23 +503,6 @@ async fn main() -> Result<()> { .into() }); - let registry = tracing_subscriber::registry().with(env_filter); - - // Initialize logging based on transport type - let transport: Transport = (&cfg.transport).into(); - match transport { - Transport::Stdio => { - registry - .with( - tracing_subscriber::fmt::layer() - .with_writer(std::io::stderr) - .with_ansi(false), - ) - .init(); - } - _ => registry.with(tracing_subscriber::fmt::layer()).init(), - } - let config = config::Config::from_serve(cfg).context("Failed to load configuration")?; @@ -521,6 +525,31 @@ async fn main() -> Result<()> { let server = McpServer::new(lifecycle_manager.clone()); + // Create MCP logging layer that can forward logs to MCP clients + let mcp_layer = mcp_logging::McpLoggingLayer::new( + server.peer.clone(), + server.log_level.clone(), + ); + + let registry = tracing_subscriber::registry() + .with(env_filter) + .with(mcp_layer); + + // Initialize logging based on transport type + let transport: Transport = (&cfg.transport).into(); + match transport { + Transport::Stdio => { + registry + .with( + tracing_subscriber::fmt::layer() + .with_writer(std::io::stderr) + .with_ansi(false), + ) + .init(); + } + _ => registry.with(tracing_subscriber::fmt::layer()).init(), + } + // Start background component loading let server_clone = server.clone(); let lifecycle_manager_clone = lifecycle_manager.clone(); diff --git a/src/mcp_logging.rs b/src/mcp_logging.rs new file mode 100644 index 00000000..8e0f62d5 --- /dev/null +++ b/src/mcp_logging.rs @@ -0,0 +1,119 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT license. + +//! MCP logging layer for tracing +//! +//! This module provides a tracing layer that forwards log messages to MCP clients +//! via logging notifications according to the MCP protocol specification. + +use std::sync::{Arc, Mutex}; + +use rmcp::model::{LoggingLevel, LoggingMessageNotificationParam}; +use tracing::{Event, Level, Subscriber}; +use tracing_subscriber::layer::Context; +use tracing_subscriber::Layer; + +/// A tracing layer that forwards log messages to MCP clients +pub struct McpLoggingLayer { + peer: Arc>>>, + min_level: Arc>>, +} + +impl McpLoggingLayer { + /// Create a new MCP logging layer + pub fn new( + peer: Arc>>>, + min_level: Arc>>, + ) -> Self { + Self { peer, min_level } + } + + /// Convert tracing Level to MCP LoggingLevel + fn tracing_to_mcp_level(level: &Level) -> LoggingLevel { + match *level { + Level::TRACE => LoggingLevel::Debug, + Level::DEBUG => LoggingLevel::Debug, + Level::INFO => LoggingLevel::Info, + Level::WARN => LoggingLevel::Warning, + Level::ERROR => LoggingLevel::Error, + } + } + + /// Check if a log level should be forwarded based on the current minimum level + fn should_forward(&self, level: LoggingLevel) -> bool { + let min_level = self.min_level.lock().unwrap(); + if let Some(min) = *min_level { + // Compare log levels - lower numeric value means higher severity + // Emergency=0, Alert=1, Critical=2, Error=3, Warning=4, Notice=5, Info=6, Debug=7 + (level as u8) <= (min as u8) + } else { + // If no level is set, don't forward any logs + false + } + } +} + +impl Layer for McpLoggingLayer { + fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) { + let metadata = event.metadata(); + let mcp_level = Self::tracing_to_mcp_level(metadata.level()); + + // Check if we should forward this log level + if !self.should_forward(mcp_level) { + return; + } + + // Get the peer + let peer_guard = self.peer.lock().unwrap(); + let peer = match peer_guard.as_ref() { + Some(p) => p.clone(), + None => return, // No peer available yet + }; + drop(peer_guard); + + // Extract message and fields from the event + let mut visitor = McpVisitor::default(); + event.record(&mut visitor); + + let data = serde_json::json!({ + "message": visitor.message, + "target": metadata.target(), + "timestamp": chrono::Utc::now().to_rfc3339(), + }); + + let logger = Some(metadata.target().to_string()); + + // Send the notification in a fire-and-forget manner + let param = LoggingMessageNotificationParam { + level: mcp_level, + logger, + data, + }; + + tokio::spawn(async move { + if let Err(e) = peer.notify_logging_message(param).await { + eprintln!("Failed to send MCP logging notification: {}", e); + } + }); + } +} + +/// Visitor to extract message from tracing events +#[derive(Default)] +struct McpVisitor { + message: String, +} + +impl tracing::field::Visit for McpVisitor { + fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) { + if field.name() == "message" { + self.message = format!("{:?}", value); + } + } + + fn record_str(&mut self, field: &tracing::field::Field, value: &str) { + if field.name() == "message" { + self.message = value.to_string(); + } + } +} diff --git a/tests/mcp_logging_test.rs b/tests/mcp_logging_test.rs new file mode 100644 index 00000000..d5f26c97 --- /dev/null +++ b/tests/mcp_logging_test.rs @@ -0,0 +1,233 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT license. + +//! Integration tests for MCP logging functionality + +use std::process::Stdio; +use std::time::Duration; + +use anyhow::{Context, Result}; +use serde_json::Value; +use tokio::io::{AsyncBufReadExt, AsyncWriteExt, BufReader}; +use tokio::process::Command; + +/// Test that the server declares logging capability +#[tokio::test] +async fn test_logging_capability_declared() -> Result<()> { + // Build the binary first + let binary_path = std::env::current_dir() + .context("Failed to get current directory")? + .join("target/debug/wassette"); + + // Start wassette mcp server with stdio transport (default) + let mut child = Command::new(&binary_path) + .args(["serve"]) + .env("RUST_LOG", "off") // Disable logs to avoid stdout pollution + .stdin(Stdio::piped()) + .stdout(Stdio::piped()) + .stderr(Stdio::piped()) + .spawn() + .context("Failed to start wassette server")?; + + let stdin = child.stdin.take().context("Failed to get stdin handle")?; + let stdout = child.stdout.take().context("Failed to get stdout handle")?; + + let mut stdin = stdin; + let mut stdout = BufReader::new(stdout); + + // Give the server time to start + tokio::time::sleep(Duration::from_millis(2000)).await; + + // Send MCP initialize request + let initialize_request = r#"{"jsonrpc": "2.0", "method": "initialize", "params": {"protocolVersion": "2024-11-05", "capabilities": {}, "clientInfo": {"name": "test-client", "version": "1.0.0"}}, "id": 1} +"#; + + stdin.write_all(initialize_request.as_bytes()).await?; + stdin.flush().await?; + + // Read and verify initialize response + let mut response_line = String::new(); + tokio::time::timeout( + Duration::from_secs(10), + stdout.read_line(&mut response_line), + ) + .await + .context("Timeout waiting for initialize response")??; + + let response: Value = + serde_json::from_str(&response_line).context("Failed to parse initialize response")?; + + assert_eq!(response["jsonrpc"], "2.0"); + assert_eq!(response["id"], 1); + assert!(response["result"].is_object()); + + // Check that logging capability is declared + let capabilities = &response["result"]["capabilities"]; + assert!( + capabilities["logging"].is_object(), + "Logging capability should be declared as an object" + ); + + // Cleanup + let _ = child.kill().await; + + Ok(()) +} + +/// Test that set_level request is handled without error +#[tokio::test] +async fn test_set_level_request() -> Result<()> { + // Build the binary first + let binary_path = std::env::current_dir() + .context("Failed to get current directory")? + .join("target/debug/wassette"); + + // Start wassette mcp server with stdio transport (default) + let mut child = Command::new(&binary_path) + .args(["serve"]) + .env("RUST_LOG", "off") // Disable logs to avoid interference + .stdin(Stdio::piped()) + .stdout(Stdio::piped()) + .stderr(Stdio::piped()) + .spawn() + .context("Failed to start wassette server")?; + + let stdin = child.stdin.take().context("Failed to get stdin handle")?; + let stdout = child.stdout.take().context("Failed to get stdout handle")?; + + let mut stdin = stdin; + let mut stdout = BufReader::new(stdout); + + // Give the server time to start + tokio::time::sleep(Duration::from_millis(2000)).await; + + // Send MCP initialize request + let initialize_request = r#"{"jsonrpc": "2.0", "method": "initialize", "params": {"protocolVersion": "2024-11-05", "capabilities": {}, "clientInfo": {"name": "test-client", "version": "1.0.0"}}, "id": 1} +"#; + + stdin.write_all(initialize_request.as_bytes()).await?; + stdin.flush().await?; + + // Read initialize response + let mut response_line = String::new(); + tokio::time::timeout( + Duration::from_secs(10), + stdout.read_line(&mut response_line), + ) + .await + .context("Timeout waiting for initialize response")??; + + // Send initialized notification + let initialized_notification = r#"{"jsonrpc": "2.0", "method": "notifications/initialized", "params": {}} +"#; + stdin.write_all(initialized_notification.as_bytes()).await?; + stdin.flush().await?; + + // Send logging/setLevel request + let set_level_request = r#"{"jsonrpc": "2.0", "method": "logging/setLevel", "params": {"level": "info"}, "id": 2} +"#; + + stdin.write_all(set_level_request.as_bytes()).await?; + stdin.flush().await?; + + // Read set_level response + let mut set_level_response = String::new(); + tokio::time::timeout( + Duration::from_secs(10), + stdout.read_line(&mut set_level_response), + ) + .await + .context("Timeout waiting for set_level response")??; + + let response: Value = + serde_json::from_str(&set_level_response).context("Failed to parse set_level response")?; + + assert_eq!(response["jsonrpc"], "2.0"); + assert_eq!(response["id"], 2); + // Result should be empty object or null + assert!( + response["result"].is_null() || response["result"].is_object(), + "set_level should return empty result" + ); + + // Cleanup + let _ = child.kill().await; + + Ok(()) +} + +/// Test setting different log levels +#[tokio::test] +async fn test_multiple_log_levels() -> Result<()> { + // Build the binary first + let binary_path = std::env::current_dir() + .context("Failed to get current directory")? + .join("target/debug/wassette"); + + // Start wassette mcp server + let mut child = Command::new(&binary_path) + .args(["serve"]) + .env("RUST_LOG", "off") // Disable logs to avoid interference + .stdin(Stdio::piped()) + .stdout(Stdio::piped()) + .stderr(Stdio::piped()) + .spawn() + .context("Failed to start wassette server")?; + + let stdin = child.stdin.take().context("Failed to get stdin handle")?; + let stdout = child.stdout.take().context("Failed to get stdout handle")?; + + let mut stdin = stdin; + let mut stdout = BufReader::new(stdout); + + // Give the server time to start + tokio::time::sleep(Duration::from_millis(2000)).await; + + // Initialize + let initialize_request = r#"{"jsonrpc": "2.0", "method": "initialize", "params": {"protocolVersion": "2024-11-05", "capabilities": {}, "clientInfo": {"name": "test-client", "version": "1.0.0"}}, "id": 1} +"#; + stdin.write_all(initialize_request.as_bytes()).await?; + stdin.flush().await?; + + let mut response_line = String::new(); + stdout.read_line(&mut response_line).await?; + + // Send initialized notification + let initialized_notification = r#"{"jsonrpc": "2.0", "method": "notifications/initialized", "params": {}} +"#; + stdin.write_all(initialized_notification.as_bytes()).await?; + stdin.flush().await?; + + // Test different log levels + let levels = ["debug", "info", "warning", "error"]; + for (idx, level) in levels.iter().enumerate() { + let set_level_request = format!( + r#"{{"jsonrpc": "2.0", "method": "logging/setLevel", "params": {{"level": "{}"}}, "id": {}}} +"#, + level, + idx + 2 + ); + + stdin.write_all(set_level_request.as_bytes()).await?; + stdin.flush().await?; + + let mut response = String::new(); + tokio::time::timeout(Duration::from_secs(5), stdout.read_line(&mut response)) + .await + .context(format!("Timeout for level {}", level))??; + + let parsed: Value = + serde_json::from_str(&response).context(format!("Parse error for level {}", level))?; + assert_eq!(parsed["id"], idx + 2); + assert!( + !parsed.get("error").is_some(), + "Should not have error for level {}", + level + ); + } + + // Cleanup + let _ = child.kill().await; + + Ok(()) +}