test(logging): Add tests for logging (#96)
* test(logging): implement basic logging functionality * test(logging): add comprehensive server transport tests
This commit is contained in:
parent
57f2ba265f
commit
72e7533e41
3 changed files with 336 additions and 5 deletions
|
|
@ -1,5 +1,3 @@
|
||||||
|
|
||||||
|
|
||||||
[package]
|
[package]
|
||||||
name = "rmcp"
|
name = "rmcp"
|
||||||
license = { workspace = true }
|
license = { workspace = true }
|
||||||
|
|
@ -25,7 +23,6 @@ tracing = { version = "0.1" }
|
||||||
tokio-util = { version = "0.7" }
|
tokio-util = { version = "0.7" }
|
||||||
pin-project-lite = "0.2"
|
pin-project-lite = "0.2"
|
||||||
paste = { version = "1", optional = true }
|
paste = { version = "1", optional = true }
|
||||||
|
|
||||||
# for auto generate schema
|
# for auto generate schema
|
||||||
schemars = { version = "0.8", optional = true }
|
schemars = { version = "0.8", optional = true }
|
||||||
|
|
||||||
|
|
@ -103,3 +100,8 @@ name = "test_notification"
|
||||||
required-features = ["server", "client"]
|
required-features = ["server", "client"]
|
||||||
path = "tests/test_notification.rs"
|
path = "tests/test_notification.rs"
|
||||||
|
|
||||||
|
[[test]]
|
||||||
|
name = "test_logging"
|
||||||
|
required-features = ["server", "client"]
|
||||||
|
path = "tests/test_logging.rs"
|
||||||
|
|
||||||
|
|
|
||||||
|
|
@ -610,8 +610,8 @@ pub type PromptListChangedNotification = NotificationNoParam<PromptListChangedNo
|
||||||
const_string!(ToolListChangedNotificationMethod = "notifications/tools/list_changed");
|
const_string!(ToolListChangedNotificationMethod = "notifications/tools/list_changed");
|
||||||
pub type ToolListChangedNotification = NotificationNoParam<ToolListChangedNotificationMethod>;
|
pub type ToolListChangedNotification = NotificationNoParam<ToolListChangedNotificationMethod>;
|
||||||
// 日志相关
|
// 日志相关
|
||||||
#[derive(Debug, Serialize, Deserialize, Clone, PartialEq)]
|
#[derive(Debug, Serialize, Deserialize, Clone, PartialEq, Copy)]
|
||||||
#[serde(rename_all = "camelCase")]
|
#[serde(rename_all = "lowercase")] //match spec
|
||||||
pub enum LoggingLevel {
|
pub enum LoggingLevel {
|
||||||
Debug,
|
Debug,
|
||||||
Info,
|
Info,
|
||||||
|
|
|
||||||
329
crates/rmcp/tests/test_logging.rs
Normal file
329
crates/rmcp/tests/test_logging.rs
Normal file
|
|
@ -0,0 +1,329 @@
|
||||||
|
// cargo test --features "server client" --package rmcp test_logging
|
||||||
|
use std::{
|
||||||
|
future::Future,
|
||||||
|
sync::{Arc, Mutex},
|
||||||
|
};
|
||||||
|
|
||||||
|
use rmcp::{
|
||||||
|
ClientHandler, Error as McpError, Peer, RoleClient, RoleServer, ServerHandler, ServiceExt,
|
||||||
|
model::{
|
||||||
|
LoggingLevel, LoggingMessageNotificationParam, ServerCapabilities, ServerInfo,
|
||||||
|
SetLevelRequestParam,
|
||||||
|
},
|
||||||
|
service::RequestContext,
|
||||||
|
};
|
||||||
|
use tokio::sync::Notify;
|
||||||
|
|
||||||
|
pub struct LoggingClient {
|
||||||
|
receive_signal: Arc<Notify>,
|
||||||
|
received_messages: Arc<Mutex<Vec<LoggingMessageNotificationParam>>>,
|
||||||
|
peer: Option<Peer<RoleClient>>,
|
||||||
|
}
|
||||||
|
|
||||||
|
impl ClientHandler for LoggingClient {
|
||||||
|
async fn on_logging_message(&self, params: LoggingMessageNotificationParam) {
|
||||||
|
println!("Client: Received log message: {:?}", params);
|
||||||
|
let mut messages = self.received_messages.lock().unwrap();
|
||||||
|
messages.push(params);
|
||||||
|
self.receive_signal.notify_one();
|
||||||
|
}
|
||||||
|
|
||||||
|
fn set_peer(&mut self, peer: Peer<RoleClient>) {
|
||||||
|
self.peer.replace(peer);
|
||||||
|
}
|
||||||
|
|
||||||
|
fn get_peer(&self) -> Option<Peer<RoleClient>> {
|
||||||
|
self.peer.clone()
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
pub struct TestServer {}
|
||||||
|
|
||||||
|
impl TestServer {
|
||||||
|
fn new() -> Self {
|
||||||
|
Self {}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
impl ServerHandler for TestServer {
|
||||||
|
fn get_info(&self) -> ServerInfo {
|
||||||
|
ServerInfo {
|
||||||
|
capabilities: ServerCapabilities::builder().enable_logging().build(),
|
||||||
|
..Default::default()
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
fn set_level(
|
||||||
|
&self,
|
||||||
|
request: SetLevelRequestParam,
|
||||||
|
context: RequestContext<RoleServer>,
|
||||||
|
) -> impl Future<Output = Result<(), McpError>> + Send + '_ {
|
||||||
|
let peer = context.peer;
|
||||||
|
async move {
|
||||||
|
let (data, logger) = match request.level {
|
||||||
|
LoggingLevel::Error => (
|
||||||
|
serde_json::json!({
|
||||||
|
"message": "Failed to process request",
|
||||||
|
"error_code": "E1001",
|
||||||
|
"error_details": "Connection timeout",
|
||||||
|
"timestamp": chrono::Utc::now().to_rfc3339(),
|
||||||
|
}),
|
||||||
|
Some("error_handler".to_string()),
|
||||||
|
),
|
||||||
|
LoggingLevel::Debug => (
|
||||||
|
serde_json::json!({
|
||||||
|
"message": "Processing request",
|
||||||
|
"function": "handle_request",
|
||||||
|
"line": 42,
|
||||||
|
"context": {
|
||||||
|
"request_id": "req-123",
|
||||||
|
"user_id": "user-456"
|
||||||
|
},
|
||||||
|
"timestamp": chrono::Utc::now().to_rfc3339(),
|
||||||
|
}),
|
||||||
|
Some("debug_logger".to_string()),
|
||||||
|
),
|
||||||
|
LoggingLevel::Info => (
|
||||||
|
serde_json::json!({
|
||||||
|
"message": "System status update",
|
||||||
|
"status": "healthy",
|
||||||
|
"metrics": {
|
||||||
|
"requests_per_second": 150,
|
||||||
|
"average_latency_ms": 45,
|
||||||
|
"error_rate": 0.01
|
||||||
|
},
|
||||||
|
"timestamp": chrono::Utc::now().to_rfc3339(),
|
||||||
|
}),
|
||||||
|
Some("monitoring".to_string()),
|
||||||
|
),
|
||||||
|
_ => (
|
||||||
|
serde_json::json!({
|
||||||
|
"message": format!("Message at level {:?}", request.level),
|
||||||
|
"timestamp": chrono::Utc::now().to_rfc3339(),
|
||||||
|
}),
|
||||||
|
None,
|
||||||
|
),
|
||||||
|
};
|
||||||
|
|
||||||
|
if let Err(e) = peer
|
||||||
|
.notify_logging_message(LoggingMessageNotificationParam {
|
||||||
|
level: request.level,
|
||||||
|
data,
|
||||||
|
logger,
|
||||||
|
})
|
||||||
|
.await
|
||||||
|
{
|
||||||
|
panic!("Failed to send notification: {}", e);
|
||||||
|
}
|
||||||
|
Ok(())
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
#[tokio::test]
|
||||||
|
async fn test_logging_spec_compliance() -> anyhow::Result<()> {
|
||||||
|
let (server_transport, client_transport) = tokio::io::duplex(4096);
|
||||||
|
let receive_signal = Arc::new(Notify::new());
|
||||||
|
let received_messages = Arc::new(Mutex::new(Vec::new()));
|
||||||
|
|
||||||
|
// Start server
|
||||||
|
tokio::spawn(async move {
|
||||||
|
let server = TestServer::new().serve(server_transport).await?;
|
||||||
|
|
||||||
|
// Test server can send messages before level is set
|
||||||
|
server
|
||||||
|
.peer()
|
||||||
|
.notify_logging_message(LoggingMessageNotificationParam {
|
||||||
|
level: LoggingLevel::Info,
|
||||||
|
data: serde_json::json!({
|
||||||
|
"message": "Server initiated message",
|
||||||
|
"timestamp": chrono::Utc::now().to_rfc3339(),
|
||||||
|
}),
|
||||||
|
logger: Some("test_server".to_string()),
|
||||||
|
})
|
||||||
|
.await?;
|
||||||
|
|
||||||
|
server.waiting().await?;
|
||||||
|
anyhow::Ok(())
|
||||||
|
});
|
||||||
|
|
||||||
|
let client = LoggingClient {
|
||||||
|
receive_signal: receive_signal.clone(),
|
||||||
|
received_messages: received_messages.clone(),
|
||||||
|
peer: None,
|
||||||
|
}
|
||||||
|
.serve(client_transport)
|
||||||
|
.await?;
|
||||||
|
|
||||||
|
// Verify server-initiated message
|
||||||
|
receive_signal.notified().await;
|
||||||
|
{
|
||||||
|
let mut messages = received_messages.lock().unwrap();
|
||||||
|
assert_eq!(messages.len(), 1, "Should receive server-initiated message");
|
||||||
|
messages.clear();
|
||||||
|
}
|
||||||
|
|
||||||
|
// Test level filtering and message format
|
||||||
|
for level in [
|
||||||
|
LoggingLevel::Emergency,
|
||||||
|
LoggingLevel::Warning,
|
||||||
|
LoggingLevel::Debug,
|
||||||
|
] {
|
||||||
|
client
|
||||||
|
.peer()
|
||||||
|
.set_level(SetLevelRequestParam { level })
|
||||||
|
.await?;
|
||||||
|
receive_signal.notified().await;
|
||||||
|
|
||||||
|
let mut messages = received_messages.lock().unwrap();
|
||||||
|
let msg = messages.last().unwrap();
|
||||||
|
|
||||||
|
// Verify required fields
|
||||||
|
assert_eq!(msg.level, level);
|
||||||
|
assert!(msg.data.is_object());
|
||||||
|
|
||||||
|
// Verify data format
|
||||||
|
let data = msg.data.as_object().unwrap();
|
||||||
|
assert!(data.contains_key("message"));
|
||||||
|
assert!(data.contains_key("timestamp"));
|
||||||
|
|
||||||
|
// Verify timestamp
|
||||||
|
let timestamp = data["timestamp"].as_str().unwrap();
|
||||||
|
chrono::DateTime::parse_from_rfc3339(timestamp).expect("RFC3339 timestamp");
|
||||||
|
|
||||||
|
messages.clear();
|
||||||
|
}
|
||||||
|
|
||||||
|
client.cancel().await?;
|
||||||
|
Ok(())
|
||||||
|
}
|
||||||
|
|
||||||
|
#[tokio::test]
|
||||||
|
async fn test_logging_user_scenarios() -> anyhow::Result<()> {
|
||||||
|
let (server_transport, client_transport) = tokio::io::duplex(4096);
|
||||||
|
let receive_signal = Arc::new(Notify::new());
|
||||||
|
let received_messages = Arc::new(Mutex::new(Vec::new()));
|
||||||
|
|
||||||
|
// Start server
|
||||||
|
tokio::spawn(async move {
|
||||||
|
let server = TestServer::new().serve(server_transport).await?;
|
||||||
|
server.waiting().await?;
|
||||||
|
anyhow::Ok(())
|
||||||
|
});
|
||||||
|
|
||||||
|
let client = LoggingClient {
|
||||||
|
receive_signal: receive_signal.clone(),
|
||||||
|
received_messages: received_messages.clone(),
|
||||||
|
peer: None,
|
||||||
|
}
|
||||||
|
.serve(client_transport)
|
||||||
|
.await?;
|
||||||
|
|
||||||
|
// Test 1: Error reporting scenario
|
||||||
|
// User should see detailed error information
|
||||||
|
client
|
||||||
|
.peer()
|
||||||
|
.set_level(SetLevelRequestParam {
|
||||||
|
level: LoggingLevel::Error,
|
||||||
|
})
|
||||||
|
.await?;
|
||||||
|
receive_signal.notified().await;
|
||||||
|
{
|
||||||
|
let messages = received_messages.lock().unwrap();
|
||||||
|
let msg = &messages[0];
|
||||||
|
let data = msg.data.as_object().unwrap();
|
||||||
|
assert!(
|
||||||
|
data.contains_key("error_code"),
|
||||||
|
"Error should have an error code"
|
||||||
|
);
|
||||||
|
assert!(
|
||||||
|
data.contains_key("error_details"),
|
||||||
|
"Error should have details"
|
||||||
|
);
|
||||||
|
assert!(
|
||||||
|
data.contains_key("timestamp"),
|
||||||
|
"Should know when error occurred"
|
||||||
|
);
|
||||||
|
}
|
||||||
|
|
||||||
|
// Test 2: Debug scenario
|
||||||
|
// User debugging their application should see detailed information
|
||||||
|
client
|
||||||
|
.peer()
|
||||||
|
.set_level(SetLevelRequestParam {
|
||||||
|
level: LoggingLevel::Debug,
|
||||||
|
})
|
||||||
|
.await?;
|
||||||
|
receive_signal.notified().await;
|
||||||
|
{
|
||||||
|
let messages = received_messages.lock().unwrap();
|
||||||
|
let msg = messages.last().unwrap();
|
||||||
|
let data = msg.data.as_object().unwrap();
|
||||||
|
assert!(
|
||||||
|
data.contains_key("function"),
|
||||||
|
"Debug should show function name"
|
||||||
|
);
|
||||||
|
assert!(data.contains_key("line"), "Debug should show line number");
|
||||||
|
assert!(
|
||||||
|
data.contains_key("context"),
|
||||||
|
"Debug should show execution context"
|
||||||
|
);
|
||||||
|
}
|
||||||
|
|
||||||
|
// Test 3: Production monitoring scenario
|
||||||
|
// User monitoring production should see important status updates
|
||||||
|
client
|
||||||
|
.peer()
|
||||||
|
.set_level(SetLevelRequestParam {
|
||||||
|
level: LoggingLevel::Info,
|
||||||
|
})
|
||||||
|
.await?;
|
||||||
|
receive_signal.notified().await;
|
||||||
|
{
|
||||||
|
let messages = received_messages.lock().unwrap();
|
||||||
|
let msg = messages.last().unwrap();
|
||||||
|
let data = msg.data.as_object().unwrap();
|
||||||
|
assert!(data.contains_key("status"), "Should show system status");
|
||||||
|
assert!(data.contains_key("metrics"), "Should include metrics");
|
||||||
|
}
|
||||||
|
|
||||||
|
client.cancel().await?;
|
||||||
|
Ok(())
|
||||||
|
}
|
||||||
|
|
||||||
|
#[test]
|
||||||
|
fn test_logging_level_serialization() {
|
||||||
|
// Test all levels match spec exactly
|
||||||
|
let test_cases = [
|
||||||
|
(LoggingLevel::Alert, "alert"),
|
||||||
|
(LoggingLevel::Critical, "critical"),
|
||||||
|
(LoggingLevel::Debug, "debug"),
|
||||||
|
(LoggingLevel::Emergency, "emergency"),
|
||||||
|
(LoggingLevel::Error, "error"),
|
||||||
|
(LoggingLevel::Info, "info"),
|
||||||
|
(LoggingLevel::Notice, "notice"),
|
||||||
|
(LoggingLevel::Warning, "warning"),
|
||||||
|
];
|
||||||
|
|
||||||
|
for (level, expected) in test_cases {
|
||||||
|
let serialized = serde_json::to_string(&level).unwrap();
|
||||||
|
// Remove quotes from serialized string
|
||||||
|
let serialized = serialized.trim_matches('"');
|
||||||
|
assert_eq!(
|
||||||
|
serialized, expected,
|
||||||
|
"LoggingLevel::{:?} should serialize to \"{}\"",
|
||||||
|
level, expected
|
||||||
|
);
|
||||||
|
}
|
||||||
|
|
||||||
|
// Test deserialization from spec strings
|
||||||
|
for (level, spec_string) in test_cases {
|
||||||
|
let deserialized: LoggingLevel =
|
||||||
|
serde_json::from_str(&format!("\"{}\"", spec_string)).unwrap();
|
||||||
|
assert_eq!(
|
||||||
|
deserialized, level,
|
||||||
|
"\"{}\" should deserialize to LoggingLevel::{:?}",
|
||||||
|
spec_string, level
|
||||||
|
);
|
||||||
|
}
|
||||||
|
}
|
||||||
Loading…
Reference in a new issue