From 069d01c1650ff3db84f8e69dd27299c3922b943b Mon Sep 17 00:00:00 2001 From: Dhruv Manilawala Date: Fri, 3 Jan 2025 09:33:19 +0530 Subject: [PATCH 1/7] Improve server logging --- crates/red_knot_server/src/server.rs | 5 -- crates/red_knot_server/src/server/api.rs | 3 - .../src/server/api/notifications.rs | 2 - .../src/server/api/notifications/set_trace.rs | 25 ------ crates/red_knot_server/src/trace.rs | 90 +------------------ crates/ruff_server/src/server.rs | 6 -- crates/ruff_server/src/server/api.rs | 3 - .../src/server/api/notifications.rs | 2 - .../src/server/api/notifications/set_trace.rs | 23 ----- crates/ruff_server/src/trace.rs | 90 +------------------ 10 files changed, 6 insertions(+), 243 deletions(-) delete mode 100644 crates/red_knot_server/src/server/api/notifications/set_trace.rs delete mode 100644 crates/ruff_server/src/server/api/notifications/set_trace.rs diff --git a/crates/red_knot_server/src/server.rs b/crates/red_knot_server/src/server.rs index aa7e20e817df9..7fc13d09f231b 100644 --- a/crates/red_knot_server/src/server.rs +++ b/crates/red_knot_server/src/server.rs @@ -51,10 +51,6 @@ impl Server { crate::version(), )?; - if let Some(trace) = init_params.trace { - crate::trace::set_trace_value(trace); - } - crate::message::init_messenger(connection.make_sender()); let AllSettings { @@ -73,7 +69,6 @@ impl Server { .log_level .unwrap_or(crate::trace::LogLevel::Info), global_settings.tracing.log_file.as_deref(), - init_params.client_info.as_ref(), ); let mut workspace_for_url = |url: Url| { diff --git a/crates/red_knot_server/src/server/api.rs b/crates/red_knot_server/src/server/api.rs index be1aca8637dcd..ee56e1fe64a76 100644 --- a/crates/red_knot_server/src/server/api.rs +++ b/crates/red_knot_server/src/server/api.rs @@ -52,9 +52,6 @@ pub(super) fn notification<'a>(notif: server::Notification) -> Task<'a> { notification::DidCloseNotebookHandler::METHOD => { local_notification_task::(notif) } - notification::SetTraceHandler::METHOD => { - local_notification_task::(notif) - } method => { tracing::warn!("Received notification {method} which does not have a handler."); return Task::nothing(); diff --git a/crates/red_knot_server/src/server/api/notifications.rs b/crates/red_knot_server/src/server/api/notifications.rs index 33429547d4da6..9482c44cf8c10 100644 --- a/crates/red_knot_server/src/server/api/notifications.rs +++ b/crates/red_knot_server/src/server/api/notifications.rs @@ -3,11 +3,9 @@ mod did_close; mod did_close_notebook; mod did_open; mod did_open_notebook; -mod set_trace; pub(super) use did_change::DidChangeTextDocumentHandler; pub(super) use did_close::DidCloseTextDocumentHandler; pub(super) use did_close_notebook::DidCloseNotebookHandler; pub(super) use did_open::DidOpenTextDocumentHandler; pub(super) use did_open_notebook::DidOpenNotebookHandler; -pub(super) use set_trace::SetTraceHandler; diff --git a/crates/red_knot_server/src/server/api/notifications/set_trace.rs b/crates/red_knot_server/src/server/api/notifications/set_trace.rs deleted file mode 100644 index 5ff186b01db73..0000000000000 --- a/crates/red_knot_server/src/server/api/notifications/set_trace.rs +++ /dev/null @@ -1,25 +0,0 @@ -use lsp_types::notification::SetTrace; -use lsp_types::SetTraceParams; - -use crate::server::api::traits::{NotificationHandler, SyncNotificationHandler}; -use crate::server::client::{Notifier, Requester}; -use crate::server::Result; -use crate::session::Session; - -pub(crate) struct SetTraceHandler; - -impl NotificationHandler for SetTraceHandler { - type NotificationType = SetTrace; -} - -impl SyncNotificationHandler for SetTraceHandler { - fn run( - _session: &mut Session, - _notifier: Notifier, - _requester: &mut Requester, - params: SetTraceParams, - ) -> Result<()> { - crate::trace::set_trace_value(params.value); - Ok(()) - } -} diff --git a/crates/red_knot_server/src/trace.rs b/crates/red_knot_server/src/trace.rs index 7bd27747ef3fb..7b367c780153f 100644 --- a/crates/red_knot_server/src/trace.rs +++ b/crates/red_knot_server/src/trace.rs @@ -15,77 +15,27 @@ //! Tracing will write to `stderr` by default, which should appear in the logs for most LSP clients. //! A `logFile` path can also be specified in the settings, and output will be directed there instead. use core::str; -use lsp_server::{Message, Notification}; -use lsp_types::{ - notification::{LogTrace, Notification as _}, - ClientInfo, TraceValue, -}; use serde::Deserialize; use std::{ - io::{Error as IoError, ErrorKind, Write}, path::PathBuf, str::FromStr, - sync::{Arc, Mutex, OnceLock}, + sync::{Arc, OnceLock}, }; use tracing::level_filters::LevelFilter; use tracing_subscriber::{ - fmt::{time::Uptime, writer::BoxMakeWriter, MakeWriter}, + fmt::{time::Uptime, writer::BoxMakeWriter}, layer::SubscriberExt, Layer, }; use crate::server::ClientSender; -const TRACE_ENV_KEY: &str = "RUFF_TRACE"; - static LOGGING_SENDER: OnceLock = OnceLock::new(); -static TRACE_VALUE: Mutex = Mutex::new(lsp_types::TraceValue::Off); - -pub(crate) fn set_trace_value(trace_value: TraceValue) { - let mut global_trace_value = TRACE_VALUE - .lock() - .expect("trace value mutex should be available"); - *global_trace_value = trace_value; -} - -// A tracing writer that uses LSPs logTrace method. -struct TraceLogWriter; - -impl Write for TraceLogWriter { - fn write(&mut self, buf: &[u8]) -> std::io::Result { - let message = str::from_utf8(buf).map_err(|e| IoError::new(ErrorKind::InvalidData, e))?; - LOGGING_SENDER - .get() - .expect("logging sender should be initialized at this point") - .send(Message::Notification(Notification { - method: LogTrace::METHOD.to_owned(), - params: serde_json::json!({ - "message": message - }), - })) - .map_err(|e| IoError::new(ErrorKind::Other, e))?; - Ok(buf.len()) - } - - fn flush(&mut self) -> std::io::Result<()> { - Ok(()) - } -} - -impl<'a> MakeWriter<'a> for TraceLogWriter { - type Writer = Self; - - fn make_writer(&'a self) -> Self::Writer { - Self - } -} - pub(crate) fn init_tracing( sender: ClientSender, log_level: LogLevel, log_file: Option<&std::path::Path>, - client: Option<&ClientInfo>, ) { LOGGING_SENDER .set(sender) @@ -123,15 +73,7 @@ pub(crate) fn init_tracing( let logger = match log_file { Some(file) => BoxMakeWriter::new(Arc::new(file)), - None => { - if client.is_some_and(|client| { - client.name.starts_with("Zed") || client.name.starts_with("Visual Studio Code") - }) { - BoxMakeWriter::new(TraceLogWriter) - } else { - BoxMakeWriter::new(std::io::stderr) - } - } + None => BoxMakeWriter::new(std::io::stderr), }; let subscriber = tracing_subscriber::Registry::default().with( tracing_subscriber::fmt::layer() @@ -139,7 +81,6 @@ pub(crate) fn init_tracing( .with_thread_names(true) .with_ansi(false) .with_writer(logger) - .with_filter(TraceLevelFilter) .with_filter(LogLevelFilter { filter: log_level }), ); @@ -175,9 +116,6 @@ struct LogLevelFilter { filter: LogLevel, } -/// Filters out traces if the trace value set by the client is `off`. -struct TraceLevelFilter; - impl tracing_subscriber::layer::Filter for LogLevelFilter { fn enabled( &self, @@ -197,25 +135,3 @@ impl tracing_subscriber::layer::Filter for LogLevelFilter { Some(LevelFilter::from_level(self.filter.trace_level())) } } - -impl tracing_subscriber::layer::Filter for TraceLevelFilter { - fn enabled( - &self, - _: &tracing::Metadata<'_>, - _: &tracing_subscriber::layer::Context<'_, S>, - ) -> bool { - trace_value() != lsp_types::TraceValue::Off - } -} - -#[inline] -fn trace_value() -> lsp_types::TraceValue { - std::env::var(TRACE_ENV_KEY) - .ok() - .and_then(|trace| serde_json::from_value(serde_json::Value::String(trace)).ok()) - .unwrap_or_else(|| { - *TRACE_VALUE - .lock() - .expect("trace value mutex should be available") - }) -} diff --git a/crates/ruff_server/src/server.rs b/crates/ruff_server/src/server.rs index b098b292e0c13..38f541efa506b 100644 --- a/crates/ruff_server/src/server.rs +++ b/crates/ruff_server/src/server.rs @@ -73,16 +73,11 @@ impl Server { crate::version(), )?; - if let Some(trace) = init_params.trace { - crate::trace::set_trace_value(trace); - } - crate::message::init_messenger(connection.make_sender()); let InitializeParams { initialization_options, workspace_folders, - client_info, .. } = init_params; @@ -105,7 +100,6 @@ impl Server { .log_level .unwrap_or(crate::trace::LogLevel::Info), global_settings.tracing.log_file.as_deref(), - client_info.as_ref(), ); let workspaces = Workspaces::from_workspace_folders( diff --git a/crates/ruff_server/src/server/api.rs b/crates/ruff_server/src/server/api.rs index 459ae8fe8f645..6917d0ff6c387 100644 --- a/crates/ruff_server/src/server/api.rs +++ b/crates/ruff_server/src/server/api.rs @@ -93,9 +93,6 @@ pub(super) fn notification<'a>(notif: server::Notification) -> Task<'a> { notification::DidCloseNotebook::METHOD => { local_notification_task::(notif) } - notification::SetTrace::METHOD => { - local_notification_task::(notif) - } method => { tracing::warn!("Received notification {method} which does not have a handler."); return Task::nothing(); diff --git a/crates/ruff_server/src/server/api/notifications.rs b/crates/ruff_server/src/server/api/notifications.rs index feb7771c22408..ade0c2fbd510f 100644 --- a/crates/ruff_server/src/server/api/notifications.rs +++ b/crates/ruff_server/src/server/api/notifications.rs @@ -8,7 +8,6 @@ mod did_close; mod did_close_notebook; mod did_open; mod did_open_notebook; -mod set_trace; use super::traits::{NotificationHandler, SyncNotificationHandler}; pub(super) use cancel::Cancel; @@ -21,4 +20,3 @@ pub(super) use did_close::DidClose; pub(super) use did_close_notebook::DidCloseNotebook; pub(super) use did_open::DidOpen; pub(super) use did_open_notebook::DidOpenNotebook; -pub(super) use set_trace::SetTrace; diff --git a/crates/ruff_server/src/server/api/notifications/set_trace.rs b/crates/ruff_server/src/server/api/notifications/set_trace.rs deleted file mode 100644 index 9223d9e42b237..0000000000000 --- a/crates/ruff_server/src/server/api/notifications/set_trace.rs +++ /dev/null @@ -1,23 +0,0 @@ -use crate::server::client::{Notifier, Requester}; -use crate::server::Result; -use crate::session::Session; -use lsp_types as types; -use lsp_types::notification as notif; - -pub(crate) struct SetTrace; - -impl super::NotificationHandler for SetTrace { - type NotificationType = notif::SetTrace; -} - -impl super::SyncNotificationHandler for SetTrace { - fn run( - _session: &mut Session, - _notifier: Notifier, - _requester: &mut Requester, - params: types::SetTraceParams, - ) -> Result<()> { - crate::trace::set_trace_value(params.value); - Ok(()) - } -} diff --git a/crates/ruff_server/src/trace.rs b/crates/ruff_server/src/trace.rs index 7bd27747ef3fb..7b367c780153f 100644 --- a/crates/ruff_server/src/trace.rs +++ b/crates/ruff_server/src/trace.rs @@ -15,77 +15,27 @@ //! Tracing will write to `stderr` by default, which should appear in the logs for most LSP clients. //! A `logFile` path can also be specified in the settings, and output will be directed there instead. use core::str; -use lsp_server::{Message, Notification}; -use lsp_types::{ - notification::{LogTrace, Notification as _}, - ClientInfo, TraceValue, -}; use serde::Deserialize; use std::{ - io::{Error as IoError, ErrorKind, Write}, path::PathBuf, str::FromStr, - sync::{Arc, Mutex, OnceLock}, + sync::{Arc, OnceLock}, }; use tracing::level_filters::LevelFilter; use tracing_subscriber::{ - fmt::{time::Uptime, writer::BoxMakeWriter, MakeWriter}, + fmt::{time::Uptime, writer::BoxMakeWriter}, layer::SubscriberExt, Layer, }; use crate::server::ClientSender; -const TRACE_ENV_KEY: &str = "RUFF_TRACE"; - static LOGGING_SENDER: OnceLock = OnceLock::new(); -static TRACE_VALUE: Mutex = Mutex::new(lsp_types::TraceValue::Off); - -pub(crate) fn set_trace_value(trace_value: TraceValue) { - let mut global_trace_value = TRACE_VALUE - .lock() - .expect("trace value mutex should be available"); - *global_trace_value = trace_value; -} - -// A tracing writer that uses LSPs logTrace method. -struct TraceLogWriter; - -impl Write for TraceLogWriter { - fn write(&mut self, buf: &[u8]) -> std::io::Result { - let message = str::from_utf8(buf).map_err(|e| IoError::new(ErrorKind::InvalidData, e))?; - LOGGING_SENDER - .get() - .expect("logging sender should be initialized at this point") - .send(Message::Notification(Notification { - method: LogTrace::METHOD.to_owned(), - params: serde_json::json!({ - "message": message - }), - })) - .map_err(|e| IoError::new(ErrorKind::Other, e))?; - Ok(buf.len()) - } - - fn flush(&mut self) -> std::io::Result<()> { - Ok(()) - } -} - -impl<'a> MakeWriter<'a> for TraceLogWriter { - type Writer = Self; - - fn make_writer(&'a self) -> Self::Writer { - Self - } -} - pub(crate) fn init_tracing( sender: ClientSender, log_level: LogLevel, log_file: Option<&std::path::Path>, - client: Option<&ClientInfo>, ) { LOGGING_SENDER .set(sender) @@ -123,15 +73,7 @@ pub(crate) fn init_tracing( let logger = match log_file { Some(file) => BoxMakeWriter::new(Arc::new(file)), - None => { - if client.is_some_and(|client| { - client.name.starts_with("Zed") || client.name.starts_with("Visual Studio Code") - }) { - BoxMakeWriter::new(TraceLogWriter) - } else { - BoxMakeWriter::new(std::io::stderr) - } - } + None => BoxMakeWriter::new(std::io::stderr), }; let subscriber = tracing_subscriber::Registry::default().with( tracing_subscriber::fmt::layer() @@ -139,7 +81,6 @@ pub(crate) fn init_tracing( .with_thread_names(true) .with_ansi(false) .with_writer(logger) - .with_filter(TraceLevelFilter) .with_filter(LogLevelFilter { filter: log_level }), ); @@ -175,9 +116,6 @@ struct LogLevelFilter { filter: LogLevel, } -/// Filters out traces if the trace value set by the client is `off`. -struct TraceLevelFilter; - impl tracing_subscriber::layer::Filter for LogLevelFilter { fn enabled( &self, @@ -197,25 +135,3 @@ impl tracing_subscriber::layer::Filter for LogLevelFilter { Some(LevelFilter::from_level(self.filter.trace_level())) } } - -impl tracing_subscriber::layer::Filter for TraceLevelFilter { - fn enabled( - &self, - _: &tracing::Metadata<'_>, - _: &tracing_subscriber::layer::Context<'_, S>, - ) -> bool { - trace_value() != lsp_types::TraceValue::Off - } -} - -#[inline] -fn trace_value() -> lsp_types::TraceValue { - std::env::var(TRACE_ENV_KEY) - .ok() - .and_then(|trace| serde_json::from_value(serde_json::Value::String(trace)).ok()) - .unwrap_or_else(|| { - *TRACE_VALUE - .lock() - .expect("trace value mutex should be available") - }) -} From 7ad0e668f47c0ed4c425887a223369e23bc937b6 Mon Sep 17 00:00:00 2001 From: Dhruv Manilawala Date: Tue, 7 Jan 2025 10:24:13 +0530 Subject: [PATCH 2/7] Rename `trace.rs` to `logging.rs` --- crates/red_knot_server/src/lib.rs | 2 +- .../src/logging.rs} | 24 ++++++------------- crates/ruff_server/src/lib.rs | 2 +- .../trace.rs => ruff_server/src/logging.rs} | 22 +++++------------ 4 files changed, 15 insertions(+), 35 deletions(-) rename crates/{ruff_server/src/trace.rs => red_knot_server/src/logging.rs} (77%) rename crates/{red_knot_server/src/trace.rs => ruff_server/src/logging.rs} (78%) diff --git a/crates/red_knot_server/src/lib.rs b/crates/red_knot_server/src/lib.rs index eb29c7bbe428f..7c149a9ae81c8 100644 --- a/crates/red_knot_server/src/lib.rs +++ b/crates/red_knot_server/src/lib.rs @@ -11,10 +11,10 @@ use crate::server::Server; mod message; mod edit; +mod logging; mod server; mod session; mod system; -mod trace; pub(crate) const SERVER_NAME: &str = "red-knot"; pub(crate) const DIAGNOSTIC_NAME: &str = "Red Knot"; diff --git a/crates/ruff_server/src/trace.rs b/crates/red_knot_server/src/logging.rs similarity index 77% rename from crates/ruff_server/src/trace.rs rename to crates/red_knot_server/src/logging.rs index 7b367c780153f..4e42e179fda8d 100644 --- a/crates/ruff_server/src/trace.rs +++ b/crates/red_knot_server/src/logging.rs @@ -1,19 +1,9 @@ -//! The tracing system for `ruff server`. +//! The logging system for `ruff server`. //! -//! Traces are controlled by the `logLevel` setting, along with the -//! trace level set through the LSP. On VS Code, the trace level can -//! also be set with `ruff.trace.server`. A trace level of `messages` or -//! `verbose` will enable tracing - otherwise, no traces will be shown. -//! -//! `logLevel` can be used to configure the level of tracing that is shown. -//! By default, `logLevel` is set to `"info"`. -//! -//! The server also supports the `RUFF_TRACE` environment variable, which will -//! override the trace value provided by the LSP client. Use this if there's no good way -//! to set the trace value through your editor's configuration. -//! -//! Tracing will write to `stderr` by default, which should appear in the logs for most LSP clients. -//! A `logFile` path can also be specified in the settings, and output will be directed there instead. +//! Log messages are controlled by the `logLevel` setting which defaults to `"info"`. Log messages +//! are written to `stderr` by default, which should appear in the logs for most LSP clients. A +//! `logFile` path can also be specified in the settings, and output will be directed there +//! instead. use core::str; use serde::Deserialize; use std::{ @@ -32,7 +22,7 @@ use crate::server::ClientSender; static LOGGING_SENDER: OnceLock = OnceLock::new(); -pub(crate) fn init_tracing( +pub(crate) fn init_logging( sender: ClientSender, log_level: LogLevel, log_file: Option<&std::path::Path>, @@ -122,7 +112,7 @@ impl tracing_subscriber::layer::Filter for LogLevelFilter { meta: &tracing::Metadata<'_>, _: &tracing_subscriber::layer::Context<'_, S>, ) -> bool { - let filter = if meta.target().starts_with("ruff") { + let filter = if meta.target().starts_with("red_knot") { self.filter.trace_level() } else { tracing::Level::INFO diff --git a/crates/ruff_server/src/lib.rs b/crates/ruff_server/src/lib.rs index ff0dc7ddb59b2..acde201469f8e 100644 --- a/crates/ruff_server/src/lib.rs +++ b/crates/ruff_server/src/lib.rs @@ -12,10 +12,10 @@ mod edit; mod fix; mod format; mod lint; +mod logging; mod resolve; mod server; mod session; -mod trace; pub(crate) const SERVER_NAME: &str = "ruff"; pub(crate) const DIAGNOSTIC_NAME: &str = "Ruff"; diff --git a/crates/red_knot_server/src/trace.rs b/crates/ruff_server/src/logging.rs similarity index 78% rename from crates/red_knot_server/src/trace.rs rename to crates/ruff_server/src/logging.rs index 7b367c780153f..ce603bd2cb15d 100644 --- a/crates/red_knot_server/src/trace.rs +++ b/crates/ruff_server/src/logging.rs @@ -1,19 +1,9 @@ -//! The tracing system for `ruff server`. +//! The logging system for `ruff server`. //! -//! Traces are controlled by the `logLevel` setting, along with the -//! trace level set through the LSP. On VS Code, the trace level can -//! also be set with `ruff.trace.server`. A trace level of `messages` or -//! `verbose` will enable tracing - otherwise, no traces will be shown. -//! -//! `logLevel` can be used to configure the level of tracing that is shown. -//! By default, `logLevel` is set to `"info"`. -//! -//! The server also supports the `RUFF_TRACE` environment variable, which will -//! override the trace value provided by the LSP client. Use this if there's no good way -//! to set the trace value through your editor's configuration. -//! -//! Tracing will write to `stderr` by default, which should appear in the logs for most LSP clients. -//! A `logFile` path can also be specified in the settings, and output will be directed there instead. +//! Log messages are controlled by the `logLevel` setting which defaults to `"info"`. Log messages +//! are written to `stderr` by default, which should appear in the logs for most LSP clients. A +//! `logFile` path can also be specified in the settings, and output will be directed there +//! instead. use core::str; use serde::Deserialize; use std::{ @@ -32,7 +22,7 @@ use crate::server::ClientSender; static LOGGING_SENDER: OnceLock = OnceLock::new(); -pub(crate) fn init_tracing( +pub(crate) fn init_logging( sender: ClientSender, log_level: LogLevel, log_file: Option<&std::path::Path>, From 1fca6dc49b6274babacacb95725fde9976238132 Mon Sep 17 00:00:00 2001 From: Dhruv Manilawala Date: Tue, 7 Jan 2025 10:45:03 +0530 Subject: [PATCH 3/7] Update docs --- docs/editors/setup.md | 27 +++++++++++++++------------ 1 file changed, 15 insertions(+), 12 deletions(-) diff --git a/docs/editors/setup.md b/docs/editors/setup.md index efd856787e8da..0603a6b029b5d 100644 --- a/docs/editors/setup.md +++ b/docs/editors/setup.md @@ -92,13 +92,11 @@ require('lspconfig').pyright.setup { } ``` -By default, Ruff will not show any logs. To enable logging in Neovim, you'll need to set the -[`trace`](https://neovim.io/doc/user/lsp.html#vim.lsp.ClientConfig) setting to either `messages` or `verbose`, and use the -[`logLevel`](./settings.md#loglevel) setting to change the log level: +By default, the log level for Ruff is set to `info`. To change the log level, you can set the +[`logLevel`](./settings.md#loglevel) setting: ```lua require('lspconfig').ruff.setup { - trace = 'messages', init_options = { settings = { logLevel = 'debug', @@ -107,10 +105,16 @@ require('lspconfig').ruff.setup { } ``` -By default, this will write logs to stderr which will be available in Neovim's LSP client log file +By default, Ruff will write logs to stderr which will be available in Neovim's LSP client log file (`:lua vim.print(vim.lsp.get_log_path())`). It's also possible to divert these logs to a separate file with the [`logFile`](./settings.md#logfile) setting. +To view the trace logs between Neovim and Ruff, set the log level for Neovim's LSP client to `debug`: + +```lua +vim.lsp.set_log_level('debug') +``` + ## Vim The [`vim-lsp`](https://github.com/prabirshrestha/vim-lsp) plugin can be used to configure the Ruff Language Server in Vim. @@ -274,15 +278,13 @@ preview = false preview = true ``` -By default, Ruff does not log anything to Helix. To enable logging, set the `RUFF_TRACE` environment -variable to either `messages` or `verbose`, and use the [`logLevel`](./settings.md#loglevel) setting to change -the log level: +By default, the log level for Ruff is set to `info`. To change the log level, you can set the +[`logLevel`](./settings.md#loglevel) setting: ```toml [language-server.ruff] command = "ruff" args = ["server"] -environment = { "RUFF_TRACE" = "messages" } [language-server.ruff.config.settings] logLevel = "debug" @@ -290,10 +292,11 @@ logLevel = "debug" You can also divert Ruff's logs to a separate file with the [`logFile`](./settings.md#logfile) setting. -!!! note +To view the trace logs between Helix and Ruff, pass in the `-v` (verbose) flag when starting Helix: - Setting `RUFF_TRACE=verbose` does not enable Helix's verbose mode by itself. You'll need to run - Helix with `-v` for verbose logging. +```sh +hx -v path/to/file.py +``` ## Kate From 3887d2dddb100554e94215c2cec2ede9fffd1d80 Mon Sep 17 00:00:00 2001 From: Dhruv Manilawala Date: Tue, 7 Jan 2025 10:57:58 +0530 Subject: [PATCH 4/7] Fix clippy --- crates/red_knot_server/src/server.rs | 4 ++-- crates/red_knot_server/src/session/settings.rs | 2 +- crates/ruff_server/src/server.rs | 4 ++-- crates/ruff_server/src/session/settings.rs | 2 +- 4 files changed, 6 insertions(+), 6 deletions(-) diff --git a/crates/red_knot_server/src/server.rs b/crates/red_knot_server/src/server.rs index 7fc13d09f231b..bed85f9f1f07f 100644 --- a/crates/red_knot_server/src/server.rs +++ b/crates/red_knot_server/src/server.rs @@ -62,12 +62,12 @@ impl Server { .unwrap_or_else(|| serde_json::Value::Object(serde_json::Map::default())), ); - crate::trace::init_tracing( + crate::logging::init_logging( connection.make_sender(), global_settings .tracing .log_level - .unwrap_or(crate::trace::LogLevel::Info), + .unwrap_or(crate::logging::LogLevel::Info), global_settings.tracing.log_file.as_deref(), ); diff --git a/crates/red_knot_server/src/session/settings.rs b/crates/red_knot_server/src/session/settings.rs index 0fccad470cbde..f140b9c4b1847 100644 --- a/crates/red_knot_server/src/session/settings.rs +++ b/crates/red_knot_server/src/session/settings.rs @@ -24,7 +24,7 @@ pub struct ClientSettings { #[cfg_attr(test, derive(PartialEq, Eq))] #[serde(rename_all = "camelCase")] pub(crate) struct TracingSettings { - pub(crate) log_level: Option, + pub(crate) log_level: Option, /// Path to the log file - tildes and environment variables are supported. pub(crate) log_file: Option, } diff --git a/crates/ruff_server/src/server.rs b/crates/ruff_server/src/server.rs index 38f541efa506b..e04462b96f973 100644 --- a/crates/ruff_server/src/server.rs +++ b/crates/ruff_server/src/server.rs @@ -93,12 +93,12 @@ impl Server { workspace_settings, } = all_settings; - crate::trace::init_tracing( + crate::logging::init_logging( connection.make_sender(), global_settings .tracing .log_level - .unwrap_or(crate::trace::LogLevel::Info), + .unwrap_or(crate::logging::LogLevel::Info), global_settings.tracing.log_file.as_deref(), ); diff --git a/crates/ruff_server/src/session/settings.rs b/crates/ruff_server/src/session/settings.rs index 0f6a3806f5a46..50bbd413077a8 100644 --- a/crates/ruff_server/src/session/settings.rs +++ b/crates/ruff_server/src/session/settings.rs @@ -104,7 +104,7 @@ impl ClientSettings { #[cfg_attr(test, derive(PartialEq, Eq))] #[serde(rename_all = "camelCase")] pub(crate) struct TracingSettings { - pub(crate) log_level: Option, + pub(crate) log_level: Option, /// Path to the log file - tildes and environment variables are supported. pub(crate) log_file: Option, } From f75e1faa054526d796921610a6ef5471c407a914 Mon Sep 17 00:00:00 2001 From: Dhruv Manilawala Date: Tue, 7 Jan 2025 15:18:51 +0530 Subject: [PATCH 5/7] Add trace spans for request and notification --- crates/ruff_server/src/logging.rs | 3 ++- crates/ruff_server/src/server/api.rs | 5 +++++ 2 files changed, 7 insertions(+), 1 deletion(-) diff --git a/crates/ruff_server/src/logging.rs b/crates/ruff_server/src/logging.rs index ce603bd2cb15d..af78247859a47 100644 --- a/crates/ruff_server/src/logging.rs +++ b/crates/ruff_server/src/logging.rs @@ -13,7 +13,7 @@ use std::{ }; use tracing::level_filters::LevelFilter; use tracing_subscriber::{ - fmt::{time::Uptime, writer::BoxMakeWriter}, + fmt::{format::FmtSpan, time::Uptime, writer::BoxMakeWriter}, layer::SubscriberExt, Layer, }; @@ -71,6 +71,7 @@ pub(crate) fn init_logging( .with_thread_names(true) .with_ansi(false) .with_writer(logger) + .with_span_events(FmtSpan::ENTER) .with_filter(LogLevelFilter { filter: log_level }), ); diff --git a/crates/ruff_server/src/server/api.rs b/crates/ruff_server/src/server/api.rs index 6917d0ff6c387..953c74fa05107 100644 --- a/crates/ruff_server/src/server/api.rs +++ b/crates/ruff_server/src/server/api.rs @@ -26,6 +26,9 @@ macro_rules! define_document_url { use define_document_url; pub(super) fn request<'a>(req: server::Request) -> Task<'a> { + let _span = + tracing::trace_span!("request", id = %req.id, method = req.method.as_str()).entered(); + let id = req.id.clone(); match req.method.as_str() { @@ -68,6 +71,8 @@ pub(super) fn request<'a>(req: server::Request) -> Task<'a> { } pub(super) fn notification<'a>(notif: server::Notification) -> Task<'a> { + let _span = tracing::trace_span!("notification", method = notif.method.as_str()).entered(); + match notif.method.as_str() { notification::Cancel::METHOD => local_notification_task::(notif), notification::DidChange::METHOD => { From f2c09e71654a5e5bc4360daef95dc9e7ece74687 Mon Sep 17 00:00:00 2001 From: Dhruv Manilawala Date: Tue, 7 Jan 2025 19:46:13 +0530 Subject: [PATCH 6/7] Address review comments (1) Need to address the "span" feedback (heading out now for dinner) --- crates/red_knot_server/src/logging.rs | 17 +++++------------ crates/red_knot_server/src/server.rs | 6 +----- crates/ruff_server/src/logging.rs | 17 +++++------------ crates/ruff_server/src/server.rs | 6 +----- 4 files changed, 12 insertions(+), 34 deletions(-) diff --git a/crates/red_knot_server/src/logging.rs b/crates/red_knot_server/src/logging.rs index 4e42e179fda8d..56d063f191f35 100644 --- a/crates/red_knot_server/src/logging.rs +++ b/crates/red_knot_server/src/logging.rs @@ -20,17 +20,7 @@ use tracing_subscriber::{ use crate::server::ClientSender; -static LOGGING_SENDER: OnceLock = OnceLock::new(); - -pub(crate) fn init_logging( - sender: ClientSender, - log_level: LogLevel, - log_file: Option<&std::path::Path>, -) { - LOGGING_SENDER - .set(sender) - .expect("logging sender should only be initialized once"); - +pub(crate) fn init_logging(log_level: LogLevel, log_file: Option<&std::path::Path>) { let log_file = log_file .map(|path| { // this expands `logFile` so that tildes and environment variables @@ -78,12 +68,15 @@ pub(crate) fn init_logging( .expect("should be able to set global default subscriber"); } +/// The log level for the server as provided by the client during initialization. +/// +/// The default log level is `info`. #[derive(Clone, Copy, Debug, Deserialize, Default, PartialEq, Eq, PartialOrd, Ord)] #[serde(rename_all = "lowercase")] pub(crate) enum LogLevel { - #[default] Error, Warn, + #[default] Info, Debug, Trace, diff --git a/crates/red_knot_server/src/server.rs b/crates/red_knot_server/src/server.rs index bed85f9f1f07f..4a29644a8713c 100644 --- a/crates/red_knot_server/src/server.rs +++ b/crates/red_knot_server/src/server.rs @@ -63,11 +63,7 @@ impl Server { ); crate::logging::init_logging( - connection.make_sender(), - global_settings - .tracing - .log_level - .unwrap_or(crate::logging::LogLevel::Info), + global_settings.tracing.log_level.unwrap_or_default(), global_settings.tracing.log_file.as_deref(), ); diff --git a/crates/ruff_server/src/logging.rs b/crates/ruff_server/src/logging.rs index af78247859a47..db2026b3d6b59 100644 --- a/crates/ruff_server/src/logging.rs +++ b/crates/ruff_server/src/logging.rs @@ -20,17 +20,7 @@ use tracing_subscriber::{ use crate::server::ClientSender; -static LOGGING_SENDER: OnceLock = OnceLock::new(); - -pub(crate) fn init_logging( - sender: ClientSender, - log_level: LogLevel, - log_file: Option<&std::path::Path>, -) { - LOGGING_SENDER - .set(sender) - .expect("logging sender should only be initialized once"); - +pub(crate) fn init_logging(log_level: LogLevel, log_file: Option<&std::path::Path>) { let log_file = log_file .map(|path| { // this expands `logFile` so that tildes and environment variables @@ -79,12 +69,15 @@ pub(crate) fn init_logging( .expect("should be able to set global default subscriber"); } +/// The log level for the server as provided by the client during initialization. +/// +/// The default log level is `info`. #[derive(Clone, Copy, Debug, Deserialize, Default, PartialEq, Eq, PartialOrd, Ord)] #[serde(rename_all = "lowercase")] pub(crate) enum LogLevel { - #[default] Error, Warn, + #[default] Info, Debug, Trace, diff --git a/crates/ruff_server/src/server.rs b/crates/ruff_server/src/server.rs index e04462b96f973..feba047efa1af 100644 --- a/crates/ruff_server/src/server.rs +++ b/crates/ruff_server/src/server.rs @@ -94,11 +94,7 @@ impl Server { } = all_settings; crate::logging::init_logging( - connection.make_sender(), - global_settings - .tracing - .log_level - .unwrap_or(crate::logging::LogLevel::Info), + global_settings.tracing.log_level.unwrap_or_default(), global_settings.tracing.log_file.as_deref(), ); From 14f735b85869583f7d4141e5d96a5ecdee9cf9b1 Mon Sep 17 00:00:00 2001 From: Dhruv Manilawala Date: Wed, 8 Jan 2025 09:41:29 +0530 Subject: [PATCH 7/7] Enter span locally for each request / notification --- crates/red_knot_server/src/logging.rs | 10 ++-------- crates/ruff_server/src/logging.rs | 8 +------- crates/ruff_server/src/server/api.rs | 11 +++++------ 3 files changed, 8 insertions(+), 21 deletions(-) diff --git a/crates/red_knot_server/src/logging.rs b/crates/red_knot_server/src/logging.rs index 56d063f191f35..701e8b697e391 100644 --- a/crates/red_knot_server/src/logging.rs +++ b/crates/red_knot_server/src/logging.rs @@ -1,4 +1,4 @@ -//! The logging system for `ruff server`. +//! The logging system for `red_knot server`. //! //! Log messages are controlled by the `logLevel` setting which defaults to `"info"`. Log messages //! are written to `stderr` by default, which should appear in the logs for most LSP clients. A @@ -6,11 +6,7 @@ //! instead. use core::str; use serde::Deserialize; -use std::{ - path::PathBuf, - str::FromStr, - sync::{Arc, OnceLock}, -}; +use std::{path::PathBuf, str::FromStr, sync::Arc}; use tracing::level_filters::LevelFilter; use tracing_subscriber::{ fmt::{time::Uptime, writer::BoxMakeWriter}, @@ -18,8 +14,6 @@ use tracing_subscriber::{ Layer, }; -use crate::server::ClientSender; - pub(crate) fn init_logging(log_level: LogLevel, log_file: Option<&std::path::Path>) { let log_file = log_file .map(|path| { diff --git a/crates/ruff_server/src/logging.rs b/crates/ruff_server/src/logging.rs index db2026b3d6b59..1b23bff3bddf7 100644 --- a/crates/ruff_server/src/logging.rs +++ b/crates/ruff_server/src/logging.rs @@ -6,11 +6,7 @@ //! instead. use core::str; use serde::Deserialize; -use std::{ - path::PathBuf, - str::FromStr, - sync::{Arc, OnceLock}, -}; +use std::{path::PathBuf, str::FromStr, sync::Arc}; use tracing::level_filters::LevelFilter; use tracing_subscriber::{ fmt::{format::FmtSpan, time::Uptime, writer::BoxMakeWriter}, @@ -18,8 +14,6 @@ use tracing_subscriber::{ Layer, }; -use crate::server::ClientSender; - pub(crate) fn init_logging(log_level: LogLevel, log_file: Option<&std::path::Path>) { let log_file = log_file .map(|path| { diff --git a/crates/ruff_server/src/server/api.rs b/crates/ruff_server/src/server/api.rs index 953c74fa05107..96414f1840e07 100644 --- a/crates/ruff_server/src/server/api.rs +++ b/crates/ruff_server/src/server/api.rs @@ -26,9 +26,6 @@ macro_rules! define_document_url { use define_document_url; pub(super) fn request<'a>(req: server::Request) -> Task<'a> { - let _span = - tracing::trace_span!("request", id = %req.id, method = req.method.as_str()).entered(); - let id = req.id.clone(); match req.method.as_str() { @@ -71,8 +68,6 @@ pub(super) fn request<'a>(req: server::Request) -> Task<'a> { } pub(super) fn notification<'a>(notif: server::Notification) -> Task<'a> { - let _span = tracing::trace_span!("notification", method = notif.method.as_str()).entered(); - match notif.method.as_str() { notification::Cancel::METHOD => local_notification_task::(notif), notification::DidChange::METHOD => { @@ -115,6 +110,7 @@ fn local_request_task<'a, R: traits::SyncRequestHandler>( ) -> super::Result> { let (id, params) = cast_request::(req)?; Ok(Task::local(|session, notifier, requester, responder| { + let _span = tracing::trace_span!("request", %id, method = R::METHOD).entered(); let result = R::run(session, notifier, requester, params); respond::(id, result, &responder); })) @@ -131,6 +127,7 @@ fn background_request_task<'a, R: traits::BackgroundDocumentRequestHandler>( return Box::new(|_, _| {}); }; Box::new(move |notifier, responder| { + let _span = tracing::trace_span!("request", %id, method = R::METHOD).entered(); let result = R::run_with_snapshot(snapshot, notifier, params); respond::(id, result, &responder); }) @@ -142,6 +139,7 @@ fn local_notification_task<'a, N: traits::SyncNotificationHandler>( ) -> super::Result> { let (id, params) = cast_notification::(notif)?; Ok(Task::local(move |session, notifier, requester, _| { + let _span = tracing::trace_span!("notification", method = N::METHOD).entered(); if let Err(err) = N::run(session, notifier, requester, params) { tracing::error!("An error occurred while running {id}: {err}"); show_err_msg!("Ruff encountered a problem. Check the logs for more details."); @@ -161,6 +159,7 @@ fn background_notification_thread<'a, N: traits::BackgroundDocumentNotificationH return Box::new(|_, _| {}); }; Box::new(move |notifier, _| { + let _span = tracing::trace_span!("notification", method = N::METHOD).entered(); if let Err(err) = N::run_with_snapshot(snapshot, notifier, params) { tracing::error!("An error occurred while running {id}: {err}"); show_err_msg!("Ruff encountered a problem. Check the logs for more details."); @@ -207,7 +206,7 @@ fn respond( Req: traits::RequestHandler, { if let Err(err) = &result { - tracing::error!("An error occurred with result ID {id}: {err}"); + tracing::error!("An error occurred with request ID {id}: {err}"); show_err_msg!("Ruff encountered a problem. Check the logs for more details."); } if let Err(err) = responder.respond(id, result) {