From 2a19ae92eae9f7377ad1d34bd2b7299204f38eb8 Mon Sep 17 00:00:00 2001 From: Shuhei Kadowaki <40514306+aviatesk@users.noreply.github.com> Date: Sat, 8 Aug 2026 22:01:16 +0900 Subject: [PATCH] lsp: Separate timed RPC log groups (#61452) RPC log grouping only tracked whether consecutive messages had the same transport direction. This made an untimed request appear beneath the duration header of an unrelated response when both were sent in the same direction. Before: // Send (took 53.0ms): {"jsonrpc":"2.0","id":"##CodeLensRefreshRequest#1226","result":null} {"jsonrpc":"2.0","id":53,"method":"textDocument/diagnostic"} After: // Send (took 53.0ms): {"jsonrpc":"2.0","id":"##CodeLensRefreshRequest#1226","result":null} // Send: {"jsonrpc":"2.0","id":53,"method":"textDocument/diagnostic"} Apply the same boundary handling to received messages while continuing to group consecutive untimed messages. --- Release Notes: - N/A or Added/Fixed/Improved ... --- crates/project/src/lsp_store/log_store.rs | 70 ++++++++++++++++--- crates/project/tests/integration/lsp_store.rs | 27 ++++++- 2 files changed, 85 insertions(+), 12 deletions(-) diff --git a/crates/project/src/lsp_store/log_store.rs b/crates/project/src/lsp_store/log_store.rs index 417bf82b70..ef798c5cb2 100644 --- a/crates/project/src/lsp_store/log_store.rs +++ b/crates/project/src/lsp_store/log_store.rs @@ -191,10 +191,16 @@ impl LanguageServerKind { #[derive(Debug)] pub struct LanguageServerRpcState { pub rpc_messages: VecDeque, - last_message_kind: Option, + header_state: RpcLogHeaderState, request_tracker: RpcRequestTracker, } +#[derive(Debug, Default)] +struct RpcLogHeaderState { + last_message_kind: Option, + last_message_had_elapsed: bool, +} + #[derive(Debug, Default)] struct RpcRequestTracker { pending_requests: HashMap, @@ -227,6 +233,56 @@ impl MessageKind { } } +impl RpcLogHeaderState { + fn header_for_message( + &mut self, + kind: MessageKind, + elapsed: Option, + ) -> Option { + let starts_new_group = self.last_message_kind != Some(kind) + || self.last_message_had_elapsed + || elapsed.is_some(); + self.last_message_kind = Some(kind); + self.last_message_had_elapsed = elapsed.is_some(); + + starts_new_group.then(|| { + let direction = if kind == MessageKind::Receive { + "Receive" + } else { + "Send" + }; + match elapsed { + Some(elapsed) => format!("\n// {direction} (took {}):", format_duration(elapsed)), + None => format!("\n// {direction}:"), + } + }) + } +} + +#[cfg(feature = "test-support")] +#[derive(Default)] +pub struct TestRpcLogHeaderState(RpcLogHeaderState); + +#[cfg(feature = "test-support")] +impl TestRpcLogHeaderState { + pub fn new() -> Self { + Self::default() + } + + pub fn header_for_message( + &mut self, + received: bool, + elapsed: Option, + ) -> Option { + let kind = if received { + MessageKind::Receive + } else { + MessageKind::Send + }; + self.0.header_for_message(kind, elapsed) + } +} + impl RpcRequestTracker { fn observe( &mut self, @@ -662,15 +718,7 @@ impl LogStore { }; let received = kind == MessageKind::Receive; - let direction = if received { "Receive" } else { "Send" }; - let mut header = None; - if state.last_message_kind != Some(kind) || elapsed.is_some() { - header = Some(match elapsed { - Some(elapsed) => format!("\n// {direction} (took {}):", format_duration(elapsed)), - None => format!("\n// {direction}:"), - }); - } - state.last_message_kind = Some(kind); + let header = state.header_state.header_for_message(kind, elapsed); if store_logs { let rpc_log_lines = &mut state.rpc_messages; @@ -749,7 +797,7 @@ impl LogStore { .rpc_state .get_or_insert_with(|| LanguageServerRpcState { rpc_messages: VecDeque::with_capacity(MAX_STORED_LOG_ENTRIES), - last_message_kind: None, + header_state: RpcLogHeaderState::default(), request_tracker: RpcRequestTracker::default(), }); Some(rpc_state) diff --git a/crates/project/tests/integration/lsp_store.rs b/crates/project/tests/integration/lsp_store.rs index c43db41353..db55a563c2 100644 --- a/crates/project/tests/integration/lsp_store.rs +++ b/crates/project/tests/integration/lsp_store.rs @@ -12,7 +12,10 @@ use lsp::Uri; use parking_lot::Mutex; use project::{ Project, - lsp_store::{log_store::TestRpcRequestTracker, *}, + lsp_store::{ + log_store::{TestRpcLogHeaderState, TestRpcRequestTracker}, + *, + }, }; use serde_json::json; use util::path; @@ -98,6 +101,28 @@ async fn test_removing_invisible_worktree_cleans_reused_lsp_bookkeeping(cx: &mut }); } +#[test] +fn test_rpc_log_grouping_separates_timed_messages() { + for (received, direction) in [(false, "Send"), (true, "Receive")] { + let mut header_state = TestRpcLogHeaderState::new(); + + assert_eq!( + header_state.header_for_message(received, None), + Some(format!("\n// {direction}:")) + ); + assert_eq!(header_state.header_for_message(received, None), None); + assert_eq!( + header_state.header_for_message(received, Some(Duration::from_millis(53))), + Some(format!("\n// {direction} (took 53.0ms):")) + ); + assert_eq!( + header_state.header_for_message(received, None), + Some(format!("\n// {direction}:")) + ); + assert_eq!(header_state.header_for_message(received, None), None); + } +} + #[test] fn test_rpc_request_tracker_distinguishes_request_directions() { let mut tracker = TestRpcRequestTracker::new();