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

@@ -191,10 +191,16 @@ impl LanguageServerKind {
 #[derive(Debug)]
 pub struct LanguageServerRpcState {
     pub rpc_messages: VecDeque<RpcMessage>,
-    last_message_kind: Option<MessageKind>,
+    header_state: RpcLogHeaderState,
     request_tracker: RpcRequestTracker,
 }
 
+#[derive(Debug, Default)]
+struct RpcLogHeaderState {
+    last_message_kind: Option<MessageKind>,
+    last_message_had_elapsed: bool,
+}
+
 #[derive(Debug, Default)]
 struct RpcRequestTracker {
     pending_requests: HashMap<PendingRequestKey, Instant>,
@@ -227,6 +233,56 @@ impl MessageKind {
     }
 }
 
+impl RpcLogHeaderState {
+    fn header_for_message(
+        &mut self,
+        kind: MessageKind,
+        elapsed: Option<Duration>,
+    ) -> Option<String> {
+        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<Duration>,
+    ) -> Option<String> {
+        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)

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();