lsp_log: Show messages before init and add filtering (#15893)

Allows language server logs to be published prior to the completion of
the initialize request. OmniSharp is one example of an LSP that
publishes (many) messages prior to the initialization response, and this
completely floods the Zed logs.

Also adds level filtering as demonstrated below. Again, this is due to
my experience with the massive amount of log messages that OmniSharp
publishes.

Release Notes:

- Added level filtering to language server logs

![Log Level
Filtering](https://github.com/user-attachments/assets/e3fcb7af-28cb-4787-9068-8e5e7eb3cf7d)

---------

Co-authored-by: Thorsten Ball <mrnugget@gmail.com>
This commit is contained in:
Jonathan Dickinson 2024-08-22 10:47:34 -04:00 committed by GitHub
parent 9245015d1a
commit 278864e19f
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
2 changed files with 332 additions and 111 deletions

View File

@ -8,7 +8,9 @@ use gpui::{
ViewContext, VisualContext, WeakModel, WindowContext, ViewContext, VisualContext, WeakModel, WindowContext,
}; };
use language::{LanguageServerId, LanguageServerName}; use language::{LanguageServerId, LanguageServerName};
use lsp::{notification::SetTrace, IoKind, LanguageServer, SetTraceParams, TraceValue}; use lsp::{
notification::SetTrace, IoKind, LanguageServer, MessageType, SetTraceParams, TraceValue,
};
use project::{search::SearchQuery, Project}; use project::{search::SearchQuery, Project};
use std::{borrow::Cow, sync::Arc}; use std::{borrow::Cow, sync::Arc};
use ui::{prelude::*, Button, Checkbox, ContextMenu, Label, PopoverMenu, Selection}; use ui::{prelude::*, Button, Checkbox, ContextMenu, Label, PopoverMenu, Selection};
@ -34,15 +36,76 @@ struct ProjectState {
_subscriptions: [gpui::Subscription; 2], _subscriptions: [gpui::Subscription; 2],
} }
trait Message: AsRef<str> {
type Level: Copy + std::fmt::Debug;
fn should_include(&self, _: Self::Level) -> bool {
true
}
}
struct LogMessage {
message: String,
typ: MessageType,
}
impl AsRef<str> for LogMessage {
fn as_ref(&self) -> &str {
&self.message
}
}
impl Message for LogMessage {
type Level = MessageType;
fn should_include(&self, level: Self::Level) -> bool {
match (self.typ, level) {
(MessageType::ERROR, _) => true,
(_, MessageType::ERROR) => false,
(MessageType::WARNING, _) => true,
(_, MessageType::WARNING) => false,
(MessageType::INFO, _) => true,
(_, MessageType::INFO) => false,
_ => true,
}
}
}
struct TraceMessage {
message: String,
}
impl AsRef<str> for TraceMessage {
fn as_ref(&self) -> &str {
&self.message
}
}
impl Message for TraceMessage {
type Level = ();
}
struct RpcMessage {
message: String,
}
impl AsRef<str> for RpcMessage {
fn as_ref(&self) -> &str {
&self.message
}
}
impl Message for RpcMessage {
type Level = ();
}
struct LanguageServerState { struct LanguageServerState {
kind: LanguageServerKind, kind: LanguageServerKind,
log_messages: VecDeque<String>, log_messages: VecDeque<LogMessage>,
trace_messages: VecDeque<String>, trace_messages: VecDeque<TraceMessage>,
rpc_state: Option<LanguageServerRpcState>, rpc_state: Option<LanguageServerRpcState>,
trace_level: TraceValue, trace_level: TraceValue,
_io_logs_subscription: Option<lsp::Subscription>, log_level: MessageType,
_lsp_logs_subscription: Option<lsp::Subscription>, io_logs_subscription: Option<lsp::Subscription>,
_lsp_trace_subscription: Option<lsp::Subscription>,
} }
enum LanguageServerKind { enum LanguageServerKind {
@ -60,7 +123,7 @@ impl LanguageServerKind {
} }
struct LanguageServerRpcState { struct LanguageServerRpcState {
rpc_messages: VecDeque<String>, rpc_messages: VecDeque<RpcMessage>,
last_message_kind: Option<MessageKind>, last_message_kind: Option<MessageKind>,
} }
@ -164,6 +227,7 @@ impl LogStore {
.update(&mut cx, |this, cx| { .update(&mut cx, |this, cx| {
this.add_language_server_log( this.add_language_server_log(
server_id, server_id,
MessageType::LOG,
&params.message, &params.message,
cx, cx,
); );
@ -175,7 +239,8 @@ impl LogStore {
LanguageServerKind::Global { LanguageServerKind::Global {
name: LanguageServerName(Arc::from("copilot")), name: LanguageServerName(Arc::from("copilot")),
}, },
server.clone(), server.server_id(),
Some(server.clone()),
cx, cx,
); );
} }
@ -226,7 +291,8 @@ impl LogStore {
LanguageServerKind::Local { LanguageServerKind::Local {
project: project.downgrade(), project: project.downgrade(),
}, },
server, server.server_id(),
Some(server),
cx, cx,
); );
} }
@ -234,8 +300,23 @@ impl LogStore {
project::Event::LanguageServerRemoved(id) => { project::Event::LanguageServerRemoved(id) => {
this.remove_language_server(*id, cx); this.remove_language_server(*id, cx);
} }
project::Event::LanguageServerLog(id, message) => { project::Event::LanguageServerLog(id, typ, message) => {
this.add_language_server_log(*id, message, cx); this.add_language_server(
LanguageServerKind::Local {
project: project.downgrade(),
},
*id,
None,
cx,
);
match typ {
project::LanguageServerLogType::Log(typ) => {
this.add_language_server_log(*id, *typ, message, cx);
}
project::LanguageServerLogType::Trace(_) => {
this.add_language_server_trace(*id, message, cx);
}
}
} }
_ => {} _ => {}
}), }),
@ -254,77 +335,56 @@ impl LogStore {
fn add_language_server( fn add_language_server(
&mut self, &mut self,
kind: LanguageServerKind, kind: LanguageServerKind,
server: Arc<LanguageServer>, server_id: LanguageServerId,
server: Option<Arc<LanguageServer>>,
cx: &mut ModelContext<Self>, cx: &mut ModelContext<Self>,
) -> Option<&mut LanguageServerState> { ) -> Option<&mut LanguageServerState> {
let server_state = self let server_state = self.language_servers.entry(server_id).or_insert_with(|| {
.language_servers cx.notify();
.entry(server.server_id()) LanguageServerState {
.or_insert_with(|| { kind,
cx.notify(); rpc_state: None,
LanguageServerState { log_messages: VecDeque::with_capacity(MAX_STORED_LOG_ENTRIES),
kind, trace_messages: VecDeque::with_capacity(MAX_STORED_LOG_ENTRIES),
rpc_state: None, trace_level: TraceValue::Off,
log_messages: VecDeque::with_capacity(MAX_STORED_LOG_ENTRIES), log_level: MessageType::LOG,
trace_messages: VecDeque::with_capacity(MAX_STORED_LOG_ENTRIES), io_logs_subscription: None,
trace_level: TraceValue::Off, }
_io_logs_subscription: None, });
_lsp_logs_subscription: None,
_lsp_trace_subscription: None,
}
});
if server.has_notification_handler::<lsp::notification::LogMessage>() if let Some(server) = server.filter(|_| server_state.io_logs_subscription.is_none()) {
|| server.has_notification_handler::<lsp::notification::LogTrace>() let io_tx = self.io_tx.clone();
{ let server_id = server.server_id();
// Another event wants to re-add the server that was already added and subscribed to, avoid doing it again. server_state.io_logs_subscription = Some(server.on_io(move |io_kind, message| {
return Some(server_state); io_tx
.unbounded_send((server_id, io_kind, message.to_string()))
.ok();
}));
} }
let io_tx = self.io_tx.clone();
let server_id = server.server_id();
server_state._io_logs_subscription = Some(server.on_io(move |io_kind, message| {
io_tx
.unbounded_send((server_id, io_kind, message.to_string()))
.ok();
}));
let this = cx.handle().downgrade();
server_state._lsp_logs_subscription =
Some(server.on_notification::<lsp::notification::LogMessage, _>({
let this = this.clone();
move |params, mut cx| {
if let Some(this) = this.upgrade() {
this.update(&mut cx, |this, cx| {
this.add_language_server_log(server_id, &params.message, cx);
})
.ok();
}
}
}));
server_state._lsp_trace_subscription =
Some(server.on_notification::<lsp::notification::LogTrace, _>({
move |params, mut cx| {
if let Some(this) = this.upgrade() {
this.update(&mut cx, |this, cx| {
this.add_language_server_trace(server_id, &params.message, cx);
})
.ok();
}
}
}));
Some(server_state) Some(server_state)
} }
fn add_language_server_log( fn add_language_server_log(
&mut self, &mut self,
id: LanguageServerId, id: LanguageServerId,
typ: MessageType,
message: &str, message: &str,
cx: &mut ModelContext<Self>, cx: &mut ModelContext<Self>,
) -> Option<()> { ) -> Option<()> {
let language_server_state = self.get_language_server_state(id)?; let language_server_state = self.get_language_server_state(id)?;
let log_lines = &mut language_server_state.log_messages; let log_lines = &mut language_server_state.log_messages;
Self::add_language_server_message(log_lines, id, message, LogKind::Logs, cx); Self::add_language_server_message(
log_lines,
id,
LogMessage {
message: message.trim_end().to_string(),
typ,
},
language_server_state.log_level,
LogKind::Logs,
cx,
);
Some(()) Some(())
} }
@ -337,28 +397,39 @@ impl LogStore {
let language_server_state = self.get_language_server_state(id)?; let language_server_state = self.get_language_server_state(id)?;
let log_lines = &mut language_server_state.trace_messages; let log_lines = &mut language_server_state.trace_messages;
Self::add_language_server_message(log_lines, id, message, LogKind::Trace, cx); Self::add_language_server_message(
log_lines,
id,
TraceMessage {
message: message.trim_end().to_string(),
},
(),
LogKind::Trace,
cx,
);
Some(()) Some(())
} }
fn add_language_server_message( fn add_language_server_message<T: Message>(
log_lines: &mut VecDeque<String>, log_lines: &mut VecDeque<T>,
id: LanguageServerId, id: LanguageServerId,
message: &str, message: T,
current_severity: <T as Message>::Level,
kind: LogKind, kind: LogKind,
cx: &mut ModelContext<Self>, cx: &mut ModelContext<Self>,
) { ) {
while log_lines.len() >= MAX_STORED_LOG_ENTRIES { while log_lines.len() >= MAX_STORED_LOG_ENTRIES {
log_lines.pop_front(); log_lines.pop_front();
} }
let message = message.trim(); let entry: &str = message.as_ref();
log_lines.push_back(message.to_string()); let entry = entry.to_string();
cx.emit(Event::NewServerLogEntry { let visible = message.should_include(current_severity);
id, log_lines.push_back(message);
entry: message.to_string(),
kind, if visible {
}); cx.emit(Event::NewServerLogEntry { id, entry, kind });
cx.notify(); cx.notify();
}
} }
fn remove_language_server(&mut self, id: LanguageServerId, cx: &mut ModelContext<Self>) { fn remove_language_server(&mut self, id: LanguageServerId, cx: &mut ModelContext<Self>) {
@ -366,12 +437,14 @@ impl LogStore {
cx.notify(); cx.notify();
} }
fn server_logs(&self, server_id: LanguageServerId) -> Option<&VecDeque<String>> { fn server_logs(&self, server_id: LanguageServerId) -> Option<&VecDeque<LogMessage>> {
Some(&self.language_servers.get(&server_id)?.log_messages) Some(&self.language_servers.get(&server_id)?.log_messages)
} }
fn server_trace(&self, server_id: LanguageServerId) -> Option<&VecDeque<String>> {
fn server_trace(&self, server_id: LanguageServerId) -> Option<&VecDeque<TraceMessage>> {
Some(&self.language_servers.get(&server_id)?.trace_messages) Some(&self.language_servers.get(&server_id)?.trace_messages)
} }
fn server_ids_for_project<'a>( fn server_ids_for_project<'a>(
&'a self, &'a self,
lookup_project: &'a WeakModel<Project>, lookup_project: &'a WeakModel<Project>,
@ -425,7 +498,7 @@ impl LogStore {
IoKind::StdIn => false, IoKind::StdIn => false,
IoKind::StdErr => { IoKind::StdErr => {
let message = format!("stderr: {}", message.trim()); let message = format!("stderr: {}", message.trim());
self.add_language_server_log(language_server_id, &message, cx); self.add_language_server_log(language_server_id, MessageType::LOG, &message, cx);
return Some(()); return Some(());
} }
}; };
@ -446,7 +519,9 @@ impl LogStore {
MessageKind::Send => SEND_LINE, MessageKind::Send => SEND_LINE,
MessageKind::Receive => RECEIVE_LINE, MessageKind::Receive => RECEIVE_LINE,
}; };
rpc_log_lines.push_back(line_before_message.to_string()); rpc_log_lines.push_back(RpcMessage {
message: line_before_message.to_string(),
});
cx.emit(Event::NewServerLogEntry { cx.emit(Event::NewServerLogEntry {
id: language_server_id, id: language_server_id,
entry: line_before_message.to_string(), entry: line_before_message.to_string(),
@ -458,7 +533,9 @@ impl LogStore {
rpc_log_lines.pop_front(); rpc_log_lines.pop_front();
} }
let message = message.trim(); let message = message.trim();
rpc_log_lines.push_back(message.to_string()); rpc_log_lines.push_back(RpcMessage {
message: message.to_string(),
});
cx.emit(Event::NewServerLogEntry { cx.emit(Event::NewServerLogEntry {
id: language_server_id, id: language_server_id,
entry: message.to_string(), entry: message.to_string(),
@ -646,11 +723,17 @@ impl LspLogView {
} }
fn show_logs_for_server(&mut self, server_id: LanguageServerId, cx: &mut ViewContext<Self>) { fn show_logs_for_server(&mut self, server_id: LanguageServerId, cx: &mut ViewContext<Self>) {
let typ = self
.log_store
.read_with(cx, |v, _| {
v.language_servers.get(&server_id).map(|v| v.log_level)
})
.unwrap_or(MessageType::LOG);
let log_contents = self let log_contents = self
.log_store .log_store
.read(cx) .read(cx)
.server_logs(server_id) .server_logs(server_id)
.map(log_contents); .map(|v| log_contents(v, typ));
if let Some(log_contents) = log_contents { if let Some(log_contents) = log_contents {
self.current_server_id = Some(server_id); self.current_server_id = Some(server_id);
self.active_entry_kind = LogKind::Logs; self.active_entry_kind = LogKind::Logs;
@ -661,12 +744,38 @@ impl LspLogView {
} }
cx.focus(&self.focus_handle); cx.focus(&self.focus_handle);
} }
fn update_log_level(
&self,
server_id: LanguageServerId,
level: MessageType,
cx: &mut ViewContext<Self>,
) {
let log_contents = self.log_store.update(cx, |this, _| {
if let Some(state) = this.get_language_server_state(server_id) {
state.log_level = level;
}
this.server_logs(server_id).map(|v| log_contents(v, level))
});
if let Some(log_contents) = log_contents {
self.editor.update(cx, move |editor, cx| {
editor.set_text(log_contents, cx);
editor.move_to_end(&MoveToEnd, cx);
});
cx.notify();
}
cx.focus(&self.focus_handle);
}
fn show_trace_for_server(&mut self, server_id: LanguageServerId, cx: &mut ViewContext<Self>) { fn show_trace_for_server(&mut self, server_id: LanguageServerId, cx: &mut ViewContext<Self>) {
let log_contents = self let log_contents = self
.log_store .log_store
.read(cx) .read(cx)
.server_trace(server_id) .server_trace(server_id)
.map(log_contents); .map(|v| log_contents(v, ()));
if let Some(log_contents) = log_contents { if let Some(log_contents) = log_contents {
self.current_server_id = Some(server_id); self.current_server_id = Some(server_id);
self.active_entry_kind = LogKind::Trace; self.active_entry_kind = LogKind::Trace;
@ -686,7 +795,7 @@ impl LspLogView {
let rpc_log = self.log_store.update(cx, |log_store, _| { let rpc_log = self.log_store.update(cx, |log_store, _| {
log_store log_store
.enable_rpc_trace_for_language_server(server_id) .enable_rpc_trace_for_language_server(server_id)
.map(|state| log_contents(&state.rpc_messages)) .map(|state| log_contents(&state.rpc_messages, ()))
}); });
if let Some(rpc_log) = rpc_log { if let Some(rpc_log) = rpc_log {
self.current_server_id = Some(server_id); self.current_server_id = Some(server_id);
@ -758,16 +867,25 @@ impl LspLogView {
} }
} }
fn log_contents(lines: &VecDeque<String>) -> String { fn log_filter<T: Message>(line: &T, cmp: <T as Message>::Level) -> Option<&str> {
let (a, b) = lines.as_slices(); if line.should_include(cmp) {
let log_contents = a.join("\n"); Some(line.as_ref())
if b.is_empty() {
log_contents
} else { } else {
log_contents + "\n" + &b.join("\n") None
} }
} }
fn log_contents<T: Message>(lines: &VecDeque<T>, cmp: <T as Message>::Level) -> String {
let (a, b) = lines.as_slices();
let a = a.into_iter().filter_map(move |v| log_filter(v, cmp));
let b = b.into_iter().filter_map(move |v| log_filter(v, cmp));
a.chain(b).fold(String::new(), |mut acc, el| {
acc.push_str(el);
acc.push('\n');
acc
})
}
impl Render for LspLogView { impl Render for LspLogView {
fn render(&mut self, cx: &mut ViewContext<Self>) -> impl IntoElement { fn render(&mut self, cx: &mut ViewContext<Self>) -> impl IntoElement {
self.editor self.editor
@ -1044,8 +1162,8 @@ impl Render for LspLogToolbarItemView {
) )
.ml_2(), .ml_2(),
) )
.child(log_view.update(cx, |this, _| { .child(log_view.update(cx, |this, _| match this.active_entry_kind {
if this.active_entry_kind == LogKind::Trace { LogKind::Trace => {
let log_view = log_view.clone(); let log_view = log_view.clone();
div().child( div().child(
PopoverMenu::new("lsp-trace-level-menu") PopoverMenu::new("lsp-trace-level-menu")
@ -1095,9 +1213,60 @@ impl Render for LspLogToolbarItemView {
} }
}), }),
) )
} else {
div()
} }
LogKind::Logs => {
let log_view = log_view.clone();
div().child(
PopoverMenu::new("lsp-log-level-menu")
.anchor(AnchorCorner::TopLeft)
.trigger(Button::new(
"language_server_log_level_selector",
"Log level",
))
.menu({
let log_view = log_view.clone();
move |cx| {
let id = log_view.read(cx).current_server_id?;
let log_level = log_view.update(cx, |this, cx| {
this.log_store.update(cx, |this, _| {
Some(this.get_language_server_state(id)?.log_level)
})
})?;
ContextMenu::build(cx, |mut menu, _| {
let log_view = log_view.clone();
for (option, label) in [
(MessageType::LOG, "Log"),
(MessageType::INFO, "Info"),
(MessageType::WARNING, "Warning"),
(MessageType::ERROR, "Error"),
] {
menu = menu.entry(label, None, {
let log_view = log_view.clone();
move |cx| {
log_view.update(cx, |this, cx| {
if let Some(id) = this.current_server_id {
this.update_log_level(id, option, cx);
}
});
}
});
if option == log_level {
menu.select_last();
}
}
menu
})
.into()
}
}),
)
}
_ => div(),
})) }))
} }
} }

View File

@ -62,8 +62,8 @@ use log::error;
use lsp::{ use lsp::{
CompletionContext, DiagnosticSeverity, DiagnosticTag, DidChangeWatchedFilesRegistrationOptions, CompletionContext, DiagnosticSeverity, DiagnosticTag, DidChangeWatchedFilesRegistrationOptions,
DocumentHighlightKind, Edit, FileSystemWatcher, InsertTextFormat, LanguageServer, DocumentHighlightKind, Edit, FileSystemWatcher, InsertTextFormat, LanguageServer,
LanguageServerBinary, LanguageServerId, LspRequestFuture, MessageActionItem, OneOf, LanguageServerBinary, LanguageServerId, LspRequestFuture, MessageActionItem, MessageType,
ServerHealthStatus, ServerStatus, TextEdit, WorkDoneProgressCancelParams, OneOf, ServerHealthStatus, ServerStatus, TextEdit, WorkDoneProgressCancelParams,
}; };
use lsp_command::*; use lsp_command::*;
use node_runtime::NodeRuntime; use node_runtime::NodeRuntime;
@ -308,11 +308,17 @@ impl PartialEq for LanguageServerPromptRequest {
} }
} }
#[derive(Clone, Debug, PartialEq)]
pub enum LanguageServerLogType {
Log(MessageType),
Trace(Option<String>),
}
#[derive(Clone, Debug, PartialEq)] #[derive(Clone, Debug, PartialEq)]
pub enum Event { pub enum Event {
LanguageServerAdded(LanguageServerId), LanguageServerAdded(LanguageServerId),
LanguageServerRemoved(LanguageServerId), LanguageServerRemoved(LanguageServerId),
LanguageServerLog(LanguageServerId, String), LanguageServerLog(LanguageServerId, LanguageServerLogType, String),
Notification(String), Notification(String),
LanguageServerPrompt(LanguageServerPromptRequest), LanguageServerPrompt(LanguageServerPromptRequest),
LanguageNotFound(Model<Buffer>), LanguageNotFound(Model<Buffer>),
@ -3653,17 +3659,56 @@ impl Project {
}) })
.detach(); .detach();
language_server language_server
.on_notification::<lsp::notification::Progress, _>(move |params, mut cx| { .on_notification::<lsp::notification::Progress, _>({
if let Some(this) = project.upgrade() { let project = project.clone();
this.update(&mut cx, |this, cx| { move |params, mut cx| {
this.on_lsp_progress( if let Some(this) = project.upgrade() {
params, this.update(&mut cx, |this, cx| {
server_id, this.on_lsp_progress(
disk_based_diagnostics_progress_token.clone(), params,
cx, server_id,
); disk_based_diagnostics_progress_token.clone(),
}) cx,
.ok(); );
})
.ok();
}
}
})
.detach();
language_server
.on_notification::<lsp::notification::LogMessage, _>({
let project = project.clone();
move |params, mut cx| {
if let Some(this) = project.upgrade() {
this.update(&mut cx, |_, cx| {
cx.emit(Event::LanguageServerLog(
server_id,
LanguageServerLogType::Log(params.typ),
params.message,
));
})
.ok();
}
}
})
.detach();
language_server
.on_notification::<lsp::notification::LogTrace, _>({
let project = project.clone();
move |params, mut cx| {
if let Some(this) = project.upgrade() {
this.update(&mut cx, |_, cx| {
cx.emit(Event::LanguageServerLog(
server_id,
LanguageServerLogType::Trace(params.verbose),
params.message,
));
})
.ok();
}
} }
}) })
.detach(); .detach();
@ -3675,9 +3720,16 @@ impl Project {
(None, override_options) => initialization_options = override_options, (None, override_options) => initialization_options = override_options,
_ => {} _ => {}
} }
let language_server = cx let language_server = cx
.update(|cx| language_server.initialize(initialization_options, cx))? .update(|cx| language_server.initialize(initialization_options, cx))?
.await?; .await
.inspect_err(|_| {
if let Some(this) = project.upgrade() {
this.update(cx, |_, cx| cx.emit(Event::LanguageServerRemoved(server_id)))
.ok();
}
})?;
language_server language_server
.notify::<lsp::notification::DidChangeConfiguration>( .notify::<lsp::notification::DidChangeConfiguration>(