Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Replace tracing log functions in ruff server with LSP-compliant logging functions #11169

Open
wants to merge 3 commits into
base: main
Choose a base branch
from

Conversation

snowsignal
Copy link
Member

Summary

Closes #10968.

At the moment, the log level is always set to Info. Log level configuration will be implemented in a follow-up.

Test Plan

Add a series of logs, one for each level, to the definition of Server::new, after the logger is initialized:
Screenshot 2024-04-26 at 4 16 25 PM

You should see the following logs in the output of the VS Code extension:
Screenshot 2024-04-26 at 4 21 23 PM

@snowsignal snowsignal added the server Related to the LSP server label Apr 26, 2024
@snowsignal snowsignal added this to the Ruff Server: Beta milestone Apr 26, 2024
Copy link

github-actions bot commented Apr 26, 2024

ruff-ecosystem results

Linter (stable)

✅ ecosystem check detected no linter changes.

Linter (preview)

✅ ecosystem check detected no linter changes.

Formatter (stable)

✅ ecosystem check detected no format changes.

Formatter (preview)

✅ ecosystem check detected no format changes.

@charliermarsh
Copy link
Member

Is there an alternate design whereby we wire up tracing to emit to the LSP client? I.e., some kind of tracing configuration that would let us continue to use tracing::info! and friends, but also emit to the client?

@MichaReiser
Copy link
Member

MichaReiser commented Apr 27, 2024

@charliermarsh I think that should be possible by setting up our own subscriber that then forwards messages to the LSP.

I think the problem this approach is that it only works for ruff_server, but we will use tracing in runes too and we don't have the luxury to change all tracing calls there.

I think we need to explore an alternative approach that captures all tracing messages (subscriber) and forwards them correctly OR setup an alternative subscriber that writes e.g. to a file, although I would prefer seeing the tracing messages in vs code.

@charliermarsh
Copy link
Member

Yeah I would prefer trying to integrate this into tracing too (for those reasons, plus it's the API I would've naturally reached for if I went to write code in the LSP as a future editor / author). @snowsignal can you give it a shot?

@snowsignal
Copy link
Member Author

@charliermarsh Sure, I'll see what I can do!

@@ -46,6 +46,7 @@ impl Server {
pub fn new(worker_threads: NonZeroUsize) -> crate::Result<Self> {
let (conn, threads) = lsp::Connection::stdio();

crate::trace::init_tracing(&conn.sender, crate::trace::LogLevel::Info);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should ideally respect the log level configured in the VS Code settings or does VS code take care of filtering out log messages?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We don't have a log level configured in the VS Code settings at the moment. All we have is ruff.trace.server, but that's more a verbosity setting than something that controls the log level.

tracing::Level::WARN => Self::Warn,
tracing::Level::INFO => Self::Info,
tracing::Level::DEBUG => Self::Debug,
_ => return None,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we use a debug level instead of dropping these messages?

Comment on lines -52 to -60
fn is_enabled(&self, meta: &Metadata<'_>) -> bool {
let filter = if meta.target().starts_with("ruff") {
self.trace_level
} else {
Level::INFO
};

meta.level() <= &filter
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we still want to have some form of filtering of log messages to avoid that tracing logs from third party libraries (trace and debug) show up in our LSP logs (they can be very noisy).

The old implementation limited third-party logs to info level or higher for this.

Comment on lines +11 to +20
pub(crate) fn init_tracing(sender: &ClientSender, filter: LogLevel) {
LOGGING_SENDER
.set(sender.clone())
.expect("logging sender should only be initialized once");

let subscriber = tracing_subscriber::Registry::default().with(LogLayer { filter });

tracing::subscriber::set_global_default(subscriber)
.expect("should be able to set global tracing subscriberr");
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wonder what will happen now where ClientSender is a weakref. I suspect that we won't see the Main loop stopped message anymore because the logging sender is shut down by then.

I think we should unset our tracing subscriber before dropping Connection and restore the old subscriber to ensure these messages don't get lost.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should unset our tracing subscriber before dropping Connection and restore the old subscriber to ensure these messages don't get lost.

Good idea!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
server Related to the LSP server
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Server log messages should use window/logMessage
3 participants