diff --git a/.github/workflows/test-linux.yml b/.github/workflows/test-linux.yml index 8c97b869..2e084756 100644 --- a/.github/workflows/test-linux.yml +++ b/.github/workflows/test-linux.yml @@ -51,4 +51,8 @@ jobs: run: cargo build - name: Run unit tests - run: cargo test + env: + AIR_LOG_LEVEL: trace + # `--nocapture` to see our own `tracing` logs + # `--test-threads 1` to ensure `tracing` logs aren't interleaved + run: cargo test -- --nocapture --test-threads 1 diff --git a/.github/workflows/test-mac.yml b/.github/workflows/test-mac.yml index 2259a18a..dbe44a94 100644 --- a/.github/workflows/test-mac.yml +++ b/.github/workflows/test-mac.yml @@ -29,4 +29,8 @@ jobs: run: cargo build - name: Run unit tests - run: cargo test + env: + AIR_LOG_LEVEL: trace + # `--nocapture` to see our own `tracing` logs + # `--test-threads 1` to ensure `tracing` logs aren't interleaved + run: cargo test -- --nocapture --test-threads 1 diff --git a/.github/workflows/test-windows.yml b/.github/workflows/test-windows.yml index 24b16010..fa95a5b2 100644 --- a/.github/workflows/test-windows.yml +++ b/.github/workflows/test-windows.yml @@ -29,4 +29,8 @@ jobs: run: cargo build - name: Run unit tests - run: cargo test + env: + AIR_LOG_LEVEL: trace + # `--nocapture` to see our own `tracing` logs + # `--test-threads 1` to ensure `tracing` logs aren't interleaved + run: cargo test -- --nocapture --test-threads 1 diff --git a/Cargo.lock b/Cargo.lock index 8e4a7fc7..226e1976 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -498,6 +498,38 @@ version = "1.8.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9ac0150caa2ae65ca5bd83f25c7de183dea78d4d366469f148435e2acfbad0da" +[[package]] +name = "camino" +version = "1.1.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8b96ec4966b5813e2c0507c1f86115c8c5abaadc3980879c3424042a02fd1ad3" +dependencies = [ + "serde", +] + +[[package]] +name = "cargo-platform" +version = "0.1.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e35af189006b9c0f00a064685c727031e3ed2d8020f7ba284d78cc2671bd36ea" +dependencies = [ + "serde", +] + +[[package]] +name = "cargo_metadata" +version = "0.19.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8769706aad5d996120af43197bf46ef6ad0fda35216b4505f926a365a232d924" +dependencies = [ + "camino", + "cargo-platform", + "semver", + "serde", + "serde_json", + "thiserror 2.0.5", +] + [[package]] name = "case" version = "1.0.0" @@ -678,6 +710,15 @@ dependencies = [ "parking_lot_core", ] +[[package]] +name = "deranged" +version = "0.3.11" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b42b6fa04a440b495c8b04d0e71b707c585f83cb9cb28cf8cd0d976c315e31b4" +dependencies = [ + "powerfmt", +] + [[package]] name = "displaydoc" version = "0.2.5" @@ -1276,6 +1317,7 @@ dependencies = [ "biome_parser", "biome_text_size", "bytes", + "cargo_metadata", "crossbeam", "dissimilar", "futures", @@ -1284,17 +1326,19 @@ dependencies = [ "insta", "itertools", "line_ending", - "log", "lsp_test", "memchr", "serde", "serde_json", "struct-field-names-as-array", + "strum", "tests_macros", + "time", "tokio", "tokio-util", "tower-lsp 0.20.0 (git+https://github.com/lionel-/tower-lsp?branch=bugfix%2Fpatches)", "tracing", + "tracing-subscriber", "tree-sitter", "tree-sitter-r", "triomphe", @@ -1360,6 +1404,31 @@ dependencies = [ "windows-sys 0.52.0", ] +[[package]] +name = "nu-ansi-term" +version = "0.46.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84" +dependencies = [ + "overload", + "winapi", +] + +[[package]] +name = "num-conv" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "51d515d32fb182ee37cda2ccdcb92950d6a3c2893aa280e540671c2cd0f3b1d9" + +[[package]] +name = "num_threads" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5c7398b9c8b70908f6371f47ed36737907c87c52af34c268fed0bf0ceb92ead9" +dependencies = [ + "libc", +] + [[package]] name = "object" version = "0.36.5" @@ -1375,6 +1444,12 @@ version = "1.20.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "1261fe7e33c73b354eab43b1273a57c8f967d0391e80353e51f764ac02cf6775" +[[package]] +name = "overload" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39" + [[package]] name = "oxc_resolver" version = "1.12.0" @@ -1480,6 +1555,12 @@ version = "0.3.31" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "953ec861398dccce10c670dfeaf3ec4911ca479e9c02154b3a215178c5f566f2" +[[package]] +name = "powerfmt" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "439ee305def115ba05938db6eb1644ff94165c5ab5e9420d1c1bcedbba909391" + [[package]] name = "proc-macro-error" version = "1.0.4" @@ -1638,6 +1719,12 @@ dependencies = [ "untrusted", ] +[[package]] +name = "rustversion" +version = "1.0.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0e819f2bc632f285be6d7cd36e25940d45b2391dd6d9b939e79de557f7014248" + [[package]] name = "ryu" version = "1.0.18" @@ -1685,6 +1772,15 @@ version = "1.2.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "94143f37725109f92c262ed2cf5e59bce7498c01bcc1502d7b9afe439a4e9f49" +[[package]] +name = "semver" +version = "1.0.24" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3cb6eb87a131f756572d7fb904f6e7b68633f09cca868c5df1c4b8d1a694bbba" +dependencies = [ + "serde", +] + [[package]] name = "serde" version = "1.0.215" @@ -1751,6 +1847,15 @@ dependencies = [ "syn 2.0.90", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + [[package]] name = "shlex" version = "1.3.0" @@ -1855,6 +1960,28 @@ dependencies = [ "syn 2.0.90", ] +[[package]] +name = "strum" +version = "0.26.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8fec0f0aef304996cf250b31b5a10dee7980c85da9d759361292b8bca5a18f06" +dependencies = [ + "strum_macros", +] + +[[package]] +name = "strum_macros" +version = "0.26.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4c6bee85a5a24955dc440386795aa378cd9cf82acd5f764469152d2270e581be" +dependencies = [ + "heck", + "proc-macro2", + "quote", + "rustversion", + "syn 2.0.90", +] + [[package]] name = "subtle" version = "2.6.1" @@ -1979,6 +2106,49 @@ dependencies = [ "syn 2.0.90", ] +[[package]] +name = "thread_local" +version = "1.1.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8b9ef9bad013ada3808854ceac7b46812a6465ba368859a37e2100283d2d719c" +dependencies = [ + "cfg-if", + "once_cell", +] + +[[package]] +name = "time" +version = "0.3.37" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "35e7868883861bd0e56d9ac6efcaaca0d6d5d82a2a7ec8209ff492c07cf37b21" +dependencies = [ + "deranged", + "itoa", + "libc", + "num-conv", + "num_threads", + "powerfmt", + "serde", + "time-core", + "time-macros", +] + +[[package]] +name = "time-core" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ef927ca75afb808a4d64dd374f00a2adf8d0fcff8e7b184af886c3c87ec4a3f3" + +[[package]] +name = "time-macros" +version = "0.2.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2834e6017e3e5e4b9834939793b282bc03b37a3336245fa820e35e233e2a85de" +dependencies = [ + "num-conv", + "time-core", +] + [[package]] name = "tinystr" version = "0.7.6" @@ -2152,6 +2322,33 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c06d3da6113f116aaee68e4d601191614c9053067f9ab7f6edbcb161237daa54" dependencies = [ "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e8189decb5ac0fa7bc8b96b7cb9b2701d60d48805aca84a238004d665fcc4008" +dependencies = [ + "nu-ansi-term", + "sharded-slab", + "smallvec", + "thread_local", + "time", + "tracing-core", + "tracing-log", ] [[package]] @@ -2276,6 +2473,12 @@ dependencies = [ "getrandom", ] +[[package]] +name = "valuable" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d" + [[package]] name = "vcpkg" version = "0.2.15" @@ -2319,6 +2522,22 @@ dependencies = [ "rustls-pki-types", ] +[[package]] +name = "winapi" +version = "0.3.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5c839a674fcd7a98952e593242ea400abe93992746761e38641405d28b00f419" +dependencies = [ + "winapi-i686-pc-windows-gnu", + "winapi-x86_64-pc-windows-gnu", +] + +[[package]] +name = "winapi-i686-pc-windows-gnu" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6" + [[package]] name = "winapi-util" version = "0.1.9" @@ -2328,6 +2547,12 @@ dependencies = [ "windows-sys 0.59.0", ] +[[package]] +name = "winapi-x86_64-pc-windows-gnu" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f" + [[package]] name = "windows-sys" version = "0.52.0" diff --git a/Cargo.toml b/Cargo.toml index ee989634..b6b56566 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -45,6 +45,7 @@ biome_string_case = { git = "https://github.com/biomejs/biome", rev = "2648fa420 biome_text_size = { git = "https://github.com/biomejs/biome", rev = "2648fa4201be4afd26f44eca1a4e77aac0a67272" } biome_unicode_table = { git = "https://github.com/biomejs/biome", rev = "2648fa4201be4afd26f44eca1a4e77aac0a67272" } bytes = "1.8.0" +cargo_metadata = "0.19.1" clap = { version = "4.5.20", features = ["derive"] } crossbeam = "0.8.4" dissimilar = "1.0.9" @@ -55,19 +56,21 @@ ignore = "0.4.23" insta = "1.40.0" itertools = "0.13.0" line-index = "0.1.2" -log = "0.4.22" memchr = "2.7.4" path-absolutize = "3.1.1" proc-macro2 = "1.0.86" serde = { version = "1.0.215", features = ["derive"] } serde_json = "1.0.132" struct-field-names-as-array = "0.3.0" +strum = "0.26" +time = "0.3.37" thiserror = "2.0.5" tokio = { version = "1.41.1" } tokio-util = "0.7.12" # For https://github.com/ebkalderon/tower-lsp/pull/428 tower-lsp = { git = "https://github.com/lionel-/tower-lsp", branch = "bugfix/patches" } tracing = { version = "0.1.40", default-features = false, features = ["std"] } +tracing-subscriber = "0.3.19" tree-sitter = "0.23.0" tree-sitter-r = { git = "https://github.com/r-lib/tree-sitter-r", rev = "a0d3e3307489c3ca54da8c7b5b4e0c5f5fd6953a" } triomphe = "0.1.14" diff --git a/crates/lsp/Cargo.toml b/crates/lsp/Cargo.toml index 8eab38e0..5bf1e568 100644 --- a/crates/lsp/Cargo.toml +++ b/crates/lsp/Cargo.toml @@ -25,23 +25,22 @@ dissimilar.workspace = true futures.workspace = true itertools.workspace = true line_ending.workspace = true -log.workspace = true memchr.workspace = true serde.workspace = true serde_json.workspace = true struct-field-names-as-array.workspace = true +strum = { workspace = true, features = ["derive"] } +time = { workspace = true } tokio = { workspace = true, features = ["full"] } tower-lsp.workspace = true tracing.workspace = true +tracing-subscriber = { workspace = true, features = ["ansi", "local-time"] } tree-sitter.workspace = true tree-sitter-r.workspace = true triomphe.workspace = true url.workspace = true uuid = { workspace = true, features = ["v4"] } -[lints] -workspace = true - [dev-dependencies] assert_matches.workspace = true bytes.workspace = true @@ -52,3 +51,9 @@ lsp_test.workspace = true memchr.workspace = true tests_macros.workspace = true tokio-util.workspace = true + +[build-dependencies] +cargo_metadata.workspace = true + +[lints] +workspace = true diff --git a/crates/lsp/build.rs b/crates/lsp/build.rs new file mode 100644 index 00000000..17cde13a --- /dev/null +++ b/crates/lsp/build.rs @@ -0,0 +1,34 @@ +use std::env; +use std::fs; +use std::path::Path; + +extern crate cargo_metadata; + +fn main() { + write_workspace_crate_names(); +} + +/// Write out a constant array of air crate names as `AIR_CRATE_NAMES` at build time +fn write_workspace_crate_names() { + let dir = env::var_os("OUT_DIR").unwrap(); + let path = Path::new(&dir).join("crates.rs"); + + // Equivalent to `cargo metadata --no-deps` + let mut cmd = cargo_metadata::MetadataCommand::new(); + cmd.no_deps(); + let metadata = cmd.exec().unwrap(); + + let packages: Vec = metadata + .workspace_packages() + .iter() + .map(|package| package.name.clone()) + .map(|package| String::from("\"") + package.as_str() + "\",") + .collect(); + + let packages = packages.join(" "); + + let contents = format!("pub(crate) const AIR_CRATE_NAMES: &[&str] = &[{packages}];"); + + fs::write(&path, contents).unwrap(); + println!("cargo::rerun-if-changed=build.rs"); +} diff --git a/crates/lsp/src/config.rs b/crates/lsp/src/config.rs index b0633475..3c2fa069 100644 --- a/crates/lsp/src/config.rs +++ b/crates/lsp/src/config.rs @@ -95,7 +95,7 @@ impl From for DocumentConfig { if var == "tabSize" { x.tab_size } else { - log::warn!("Unknown indent alias {var}, using default"); + tracing::warn!("Unknown indent alias {var}, using default"); 2 } } diff --git a/crates/lsp/src/crates.rs b/crates/lsp/src/crates.rs new file mode 100644 index 00000000..e79951a1 --- /dev/null +++ b/crates/lsp/src/crates.rs @@ -0,0 +1,3 @@ +// Generates `AIR_CRATE_NAMES`, a const array of the crate names in the air workspace, +// see `lsp/src/build.rs` +include!(concat!(env!("OUT_DIR"), "/crates.rs")); diff --git a/crates/lsp/src/encoding.rs b/crates/lsp/src/encoding.rs index 488b55cd..be8062a6 100644 --- a/crates/lsp/src/encoding.rs +++ b/crates/lsp/src/encoding.rs @@ -34,7 +34,7 @@ fn convert_character_from_utf16_to_utf8(x: &str, character: usize) -> usize { } } - log::error!("Failed to locate UTF-16 offset of {character}. Line: '{x}'."); + tracing::error!("Failed to locate UTF-16 offset of {character}. Line: '{x}'."); 0 } @@ -52,7 +52,7 @@ fn convert_character_from_utf8_to_utf16(x: &str, character: usize) -> usize { Some(x) => x.encode_utf16().count(), None => { let n = x.len(); - log::error!( + tracing::error!( "Tried to take UTF-8 character {character}, but only {n} characters exist. Line: '{x}'." ); 0 diff --git a/crates/lsp/src/handlers_state.rs b/crates/lsp/src/handlers_state.rs index 486bd478..211eb1b2 100644 --- a/crates/lsp/src/handlers_state.rs +++ b/crates/lsp/src/handlers_state.rs @@ -33,7 +33,8 @@ use crate::config::DocumentConfig; use crate::config::VscDiagnosticsConfig; use crate::config::VscDocumentConfig; use crate::documents::Document; -use crate::main_loop::AuxiliaryEventSender; +use crate::logging; +use crate::logging::LogMessageSender; use crate::main_loop::LspState; use crate::state::workspace_uris; use crate::state::WorldState; @@ -62,7 +63,19 @@ pub(crate) fn initialize( params: InitializeParams, lsp_state: &mut LspState, state: &mut WorldState, + log_tx: LogMessageSender, ) -> anyhow::Result { + // TODO: Get user specified options from `params.initialization_options` + let log_level = None; + let dependency_log_levels = None; + + logging::init_logging( + log_tx, + log_level, + dependency_log_levels, + params.client_info.as_ref(), + ); + // Defaults to UTF-16 let mut position_encoding = None; @@ -157,7 +170,6 @@ pub(crate) fn did_change( pub(crate) fn did_close( params: DidCloseTextDocumentParams, state: &mut WorldState, - auxiliary_event_tx: &AuxiliaryEventSender, ) -> anyhow::Result<()> { let uri = params.text_document.uri; @@ -169,8 +181,6 @@ pub(crate) fn did_close( .remove(&uri) .ok_or(anyhow!("Failed to remove document for URI: {uri}"))?; - auxiliary_event_tx.log_info(format!("did_close(): closed document with URI: '{uri}'.")); - Ok(()) } diff --git a/crates/lsp/src/lib.rs b/crates/lsp/src/lib.rs index 5336aa9a..30c20aac 100644 --- a/crates/lsp/src/lib.rs +++ b/crates/lsp/src/lib.rs @@ -4,6 +4,7 @@ pub use tower_lsp::start_lsp; pub mod config; +pub mod crates; pub mod documents; pub mod encoding; pub mod from_proto; @@ -11,6 +12,7 @@ pub mod handlers; pub mod handlers_ext; pub mod handlers_format; pub mod handlers_state; +pub mod logging; pub mod main_loop; pub mod rust_analyzer; pub mod state; diff --git a/crates/lsp/src/logging.rs b/crates/lsp/src/logging.rs new file mode 100644 index 00000000..78db0373 --- /dev/null +++ b/crates/lsp/src/logging.rs @@ -0,0 +1,318 @@ +// --- source +// authors = ["Charlie Marsh"] +// license = "MIT" +// origin = "https://github.com/astral-sh/ruff/blob/03fb2e5ac1481e498f84474800b42a966e9843e1/crates/ruff_server/src/trace.rs" +// --- + +//! The logging system for `air lsp`. +//! +//! ## Air crate logs +//! +//! For air crates, a single log level is supplied as one of: error, warn, info, debug, +//! or trace, which is applied to all air crates that log. +//! +//! Resolution strategy: +//! +//! - The environment variable `AIR_LOG_LEVEL` is consulted. +//! +//! - The LSP `InitializeParams.initializationOptions.logLevel` option is consulted. This +//! can be set in VS Code / Positron using `air.logLevel`, or in Zed by supplying +//! `initialization_options`. +//! +//! - If neither are supplied, we fallback to `"info"`. +//! +//! ## Dependency crate logs +//! +//! For dependency crates, either a single log level can be supplied, or comma separated +//! `target=level` pairs can be supplied, like `tower_lsp=debug,tokio=info`. +//! +//! Resolution strategy: +//! +//! - The environment variable `AIR_DEPENDENCY_LOG_LEVELS` is consulted. +//! +//! - The LSP `InitializeParams.initializationOptions.dependencyLogLevels` option is +//! consulted. This can be set in VS Code / Positron using `air.dependencyLogLevel`, or +//! in Zed by supplying `initialization_options`. +//! +//! - If neither are supplied, we fallback to no logging for dependency crates. +//! +//! ## IDE support +//! +//! For VS Code and Zed, which are known to support `window/logMessage` well, logging will +//! emit a `window/logMessage` message. Otherwise, logging will write to `stderr`, +//! which should appear in the logs for most LSP clients. +use core::str; +use serde::Deserialize; +use std::fmt::Display; +use std::io::{Error as IoError, ErrorKind, Write}; +use std::str::FromStr; +use tokio::sync::mpsc::unbounded_channel; +use tower_lsp::lsp_types::ClientInfo; +use tower_lsp::lsp_types::MessageType; +use tower_lsp::Client; +use tracing_subscriber::filter; +use tracing_subscriber::fmt::time::LocalTime; +use tracing_subscriber::fmt::TestWriter; +use tracing_subscriber::{ + fmt::{writer::BoxMakeWriter, MakeWriter}, + layer::SubscriberExt, + Layer, +}; + +use crate::crates; + +// TODO: +// - Add `air.logLevel` and `air.dependencyLogLevels` as VS Code extension options that set +// the log levels, and pass them through the arbitrary `initializationOptions` field of +// `InitializeParams`. + +const AIR_LOG_LEVEL: &str = "AIR_LOG_LEVEL"; +const AIR_DEPENDENCY_LOG_LEVELS: &str = "AIR_DEPENDENCY_LOG_LEVELS"; + +pub(crate) struct LogMessage { + contents: String, +} + +pub(crate) type LogMessageSender = tokio::sync::mpsc::UnboundedSender; +pub(crate) type LogMessageReceiver = tokio::sync::mpsc::UnboundedReceiver; + +pub(crate) struct LogState { + client: Client, + log_rx: LogMessageReceiver, +} + +// Needed for spawning the loop +unsafe impl Sync for LogState {} + +impl LogState { + pub(crate) fn new(client: Client) -> (Self, LogMessageSender) { + let (log_tx, log_rx) = unbounded_channel::(); + let state = Self { client, log_rx }; + (state, log_tx) + } + + /// Start the log loop + /// + /// Takes ownership of log state and start the low-latency log loop. + /// + /// We use `MessageType::LOG` to prevent the middleware from adding its own + /// timestamp and log level labels. We add that ourselves through tracing. + pub(crate) async fn start(mut self) { + while let Some(message) = self.log_rx.recv().await { + self.client + .log_message(MessageType::LOG, message.contents) + .await + } + + // Channel has been closed. + // All senders have been dropped or `close()` was called. + } +} + +// A log writer that uses LSPs logMessage method. +struct LogWriter<'a> { + log_tx: &'a LogMessageSender, +} + +impl<'a> LogWriter<'a> { + fn new(log_tx: &'a LogMessageSender) -> Self { + Self { log_tx } + } +} + +impl Write for LogWriter<'_> { + fn write(&mut self, buf: &[u8]) -> std::io::Result { + let contents = str::from_utf8(buf).map_err(|e| IoError::new(ErrorKind::InvalidData, e))?; + let contents = contents.to_string(); + + // Forward the log message to the latency sensitive log thread, + // which is in charge of forwarding to the client in an async manner. + self.log_tx + .send(LogMessage { contents }) + .map_err(|e| IoError::new(ErrorKind::Other, e))?; + + Ok(buf.len()) + } + + fn flush(&mut self) -> std::io::Result<()> { + Ok(()) + } +} + +struct LogWriterMaker { + log_tx: LogMessageSender, +} + +impl LogWriterMaker { + fn new(log_tx: LogMessageSender) -> Self { + Self { log_tx } + } +} + +impl<'a> MakeWriter<'a> for LogWriterMaker { + type Writer = LogWriter<'a>; + + fn make_writer(&'a self) -> Self::Writer { + LogWriter::new(&self.log_tx) + } +} + +pub(crate) fn init_logging( + log_tx: LogMessageSender, + log_level: Option, + dependency_log_levels: Option, + client_info: Option<&ClientInfo>, +) { + let log_level = resolve_log_level(log_level); + let dependency_log_levels = resolve_dependency_log_levels(dependency_log_levels); + + let writer = if client_info.is_some_and(|client_info| { + client_info.name.starts_with("Zed") || client_info.name.starts_with("Visual Studio Code") + }) { + // These IDEs are known to support `window/logMessage` well + BoxMakeWriter::new(LogWriterMaker::new(log_tx)) + } else if is_test_client(client_info) { + // Ensures a standard `cargo test` captures output unless `-- --nocapture` is used + BoxMakeWriter::new(TestWriter::default()) + } else { + // Fallback for other editors / IDEs + BoxMakeWriter::new(std::io::stderr) + }; + + let layer = tracing_subscriber::fmt::layer() + // Spend the effort cleaning up the logs before writing them. + // Particularly useful for instrumented logs with spans. + .pretty() + // Disable ANSI escapes, those are not supported in Code + .with_ansi(false) + // Display source code file paths + .with_file(true) + // Display source code line numbers + .with_line_number(true) + // Don't display the thread ID or thread name + .with_thread_ids(false) + .with_thread_names(false) + // Don't display the event's target (module path). + // Mostly redundant with file paths. + .with_target(false) + // Display local time rather than UTC + .with_timer(LocalTime::rfc_3339()) + // Display the log level + .with_level(true) + .with_writer(writer) + .with_filter(log_filter(log_level, dependency_log_levels)); + + let subscriber = tracing_subscriber::Registry::default().with(layer); + + if is_test_client(client_info) { + // During parallel testing, `set_global_default()` gets called multiple times + // per process. That causes it to error, but we ignore this. + tracing::subscriber::set_global_default(subscriber).ok(); + } else { + tracing::subscriber::set_global_default(subscriber) + .expect("Should be able to set the global subscriber exactly once."); + } + + tracing::info!("Logging initialized with level: {log_level}"); +} + +/// We use a special `TestWriter` during tests to be compatible with `cargo test`'s +/// typical output capturing behavior. +/// +/// Important notes: +/// - `cargo test` swallows all logs unless you use `-- --nocapture`. +/// - Tests run in parallel, so logs can be interleaved unless you run `--test-threads 1`. +/// +/// We use `cargo test -- --nocapture --test-threads 1` on CI because of all of this. +fn is_test_client(client_info: Option<&ClientInfo>) -> bool { + client_info.map_or(false, |client_info| client_info.name == "AirTestClient") +} + +fn log_filter(log_level: LogLevel, dependency_log_levels: Option) -> filter::Targets { + // Initialize `filter` from dependency log levels. + // If nothing is supplied, dependency logs are completely off. + let mut filter = match dependency_log_levels { + Some(dependency_log_levels) => match filter::Targets::from_str(&dependency_log_levels) { + Ok(level) => level, + Err(_) => filter::Targets::new(), + }, + None => filter::Targets::new(), + }; + + let log_level = log_level.tracing_level(); + + // Apply the air log level to each air crate that logs + for target in crates::AIR_CRATE_NAMES { + filter = filter.with_target(*target, log_level); + } + + filter +} + +fn resolve_log_level(log_level: Option) -> LogLevel { + // Check log environment variable, this overrides any Client options + if let Some(log_level) = std::env::var(AIR_LOG_LEVEL) + .ok() + .and_then(|level| serde_json::from_value(serde_json::Value::String(level)).ok()) + { + return log_level; + } + + // Client specified log level through initialization parameters + if let Some(log_level) = log_level { + return log_level; + } + + // Default to info logs for air crates + LogLevel::Info +} + +fn resolve_dependency_log_levels(dependency_log_levels: Option) -> Option { + // Check dependency log environment variable, this overrides any Client options + if let Ok(dependency_log_levels) = std::env::var(AIR_DEPENDENCY_LOG_LEVELS) { + return Some(dependency_log_levels); + } + + // Client specified log level through initialization parameters + if dependency_log_levels.is_some() { + return dependency_log_levels; + } + + // Default to no logs for dependency crates + None +} + +#[derive(Clone, Copy, Debug, Deserialize, Default, PartialEq, Eq, PartialOrd, Ord)] +#[serde(rename_all = "lowercase")] +pub(crate) enum LogLevel { + Error, + Warn, + #[default] + Info, + Debug, + Trace, +} + +impl LogLevel { + fn tracing_level(self) -> tracing::Level { + match self { + Self::Error => tracing::Level::ERROR, + Self::Warn => tracing::Level::WARN, + Self::Info => tracing::Level::INFO, + Self::Debug => tracing::Level::DEBUG, + Self::Trace => tracing::Level::TRACE, + } + } +} + +impl Display for LogLevel { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + match self { + Self::Error => f.write_str("Error"), + Self::Warn => f.write_str("Warn"), + Self::Info => f.write_str("Info"), + Self::Debug => f.write_str("Debug"), + Self::Trace => f.write_str("Trace"), + } + } +} diff --git a/crates/lsp/src/main_loop.rs b/crates/lsp/src/main_loop.rs index 23b5af79..4f07eb21 100644 --- a/crates/lsp/src/main_loop.rs +++ b/crates/lsp/src/main_loop.rs @@ -15,9 +15,7 @@ use biome_lsp_converters::WideEncoding; use futures::StreamExt; use tokio::sync::mpsc::unbounded_channel as tokio_unbounded_channel; use tokio::task::JoinHandle; -use tower_lsp::lsp_types; use tower_lsp::lsp_types::Diagnostic; -use tower_lsp::lsp_types::MessageType; use tower_lsp::Client; use url::Url; @@ -26,6 +24,8 @@ use crate::handlers_ext; use crate::handlers_format; use crate::handlers_state; use crate::handlers_state::ConsoleInputs; +use crate::logging::LogMessageSender; +use crate::logging::LogState; use crate::state::WorldState; use crate::tower_lsp::LspMessage; use crate::tower_lsp::LspNotification; @@ -62,7 +62,6 @@ pub(crate) enum KernelNotification { #[derive(Debug)] pub(crate) enum AuxiliaryEvent { - Log(lsp_types::MessageType, String), PublishDiagnostics(Url, Vec, Option), SpawnedTask(JoinHandle>>), } @@ -85,49 +84,12 @@ impl AuxiliaryEventSender { self.inner.send(message) } - pub(crate) fn log_info(&self, message: String) { - self.log(MessageType::INFO, message); - } - pub(crate) fn log_warn(&self, message: String) { - self.log(MessageType::WARNING, message); - } - pub(crate) fn log_error(&self, message: String) { - self.log(MessageType::ERROR, message); - } - - /// Send an `AuxiliaryEvent::Log` message in a non-blocking way - fn log(&self, level: lsp_types::MessageType, message: String) { - // We're not connected to an LSP client when running unit tests - if cfg!(test) { - return; - } - - // Check that channel is still alive in case the LSP was closed. - // If closed, fallthrough. - if self - .send(AuxiliaryEvent::Log(level, message.clone())) - .is_ok() - { - return; - } - - // Log to the kernel as fallback - log::warn!("LSP channel is closed, redirecting messages to Jupyter kernel"); - - match level { - MessageType::ERROR => log::error!("{message}"), - MessageType::WARNING => log::warn!("{message}"), - _ => log::info!("{message}"), - }; - } - /// Spawn a blocking task /// /// This runs tasks that do semantic analysis on a separate thread pool to avoid /// blocking the main loop. /// - /// Can optionally return an event for the auxiliary loop (i.e. a log message or - /// diagnostics publication). + /// Can optionally return an event for the auxiliary loop (i.e. diagnostics publication). pub(crate) fn spawn_blocking_task(&self, handler: Handler) where Handler: FnOnce() -> anyhow::Result>, @@ -138,7 +100,7 @@ impl AuxiliaryEventSender { // Send the join handle to the auxiliary loop so it can log any errors // or panics if let Err(err) = self.send(AuxiliaryEvent::SpawnedTask(handle)) { - log::warn!("Failed to send task to auxiliary loop due to {err}"); + tracing::warn!("Failed to send task to auxiliary loop due to {err}"); } } } @@ -164,22 +126,23 @@ pub(crate) struct GlobalState { /// LSP client shared with tower-lsp and the log loop client: Client, - /// Event channels for the main loop. The tower-lsp methods forward + /// Event receiver channel for the main loop. The tower-lsp methods forward /// notifications and requests here via `Event::Lsp`. We also receive /// messages from the kernel via `Event::Kernel`, and from ourselves via /// `Event::Task`. - events_tx: TokioUnboundedSender, events_rx: TokioUnboundedReceiver, - /// State of the internal auxiliary loop. - /// Fully managed by the `GlobalState`. - /// Initialized as `Some()`, and converted to `None` on `start()`. + /// Auxiliary state that gets moved to the auxiliary thread, + /// and our channel for communicating with that thread. + /// Used for sending latency sensitive events like tasks and diagnostics. auxiliary_state: Option, - - /// Event channel for sending to the auxiliary loop. - /// Used for sending latency sensitive events like logs, tasks, and - /// diagnostics. auxiliary_event_tx: AuxiliaryEventSender, + + /// Log state that gets moved to the log thread, + /// and a channel for communicating with that thread which we + /// pass on to `init_logging()` during `initialize()`. + log_state: Option, + log_tx: Option, } /// Unlike `WorldState`, `ParserState` cannot be cloned and is only accessed by @@ -242,32 +205,26 @@ impl GlobalState { /// /// * `client`: The tower-lsp client shared with the tower-lsp backend /// and auxiliary loop. - pub(crate) fn new(client: Client) -> Self { + pub(crate) fn new(client: Client) -> (Self, TokioUnboundedSender) { // Transmission channel for the main loop events. Shared with the // tower-lsp backend and the Jupyter kernel. let (events_tx, events_rx) = tokio_unbounded_channel::(); + let (log_state, log_tx) = LogState::new(client.clone()); let (auxiliary_state, auxiliary_event_tx) = AuxiliaryState::new(client.clone()); - Self { + let state = Self { world: WorldState::default(), lsp_state: LspState::default(), client, + events_rx, auxiliary_state: Some(auxiliary_state), auxiliary_event_tx, - events_tx, - events_rx, - } - } - - /// Get `Event` transmission channel - pub(crate) fn events_tx(&self) -> TokioUnboundedSender { - self.events_tx.clone() - } + log_state: Some(log_state), + log_tx: Some(log_tx), + }; - /// Get `AuxiliaryEvent` transmission channel - pub(crate) fn auxiliary_event_tx(&self) -> AuxiliaryEventSender { - self.auxiliary_event_tx.clone() + (state, events_tx) } /// Start the main and auxiliary loops @@ -288,28 +245,30 @@ impl GlobalState { /// This takes ownership of all global state and handles one by one LSP /// requests, notifications, and other internal events. async fn main_loop(mut self) { - // Spawn latency-sensitive auxiliary loop. Must be first to initialise - // global transmission channel. + // Spawn latency-sensitive auxiliary and log threads. let mut set = tokio::task::JoinSet::<()>::new(); - // Move the `auxiliary_state` owned by the global state to its own thread. - // Unwrap: `start()` should only ever be called once. + // Take ownership over `log_state` and start the log thread. + // Unwrap: `start()` should only be called once. + let log_state = self.log_state.take().unwrap(); + set.spawn(async move { log_state.start().await }); + + // Take ownership over `auxiliary_state` and start the auxiliary thread. + // Unwrap: `start()` should only be called once. let auxiliary_state = self.auxiliary_state.take().unwrap(); set.spawn(async move { auxiliary_state.start().await }); loop { let event = self.next_event().await; match self.handle_event(event).await { - Err(err) => self.log_error(format!("Failure while handling event:\n{err:?}")), + Err(err) => tracing::error!("Failure while handling event:\n{err:?}"), Ok(LoopControl::Shutdown) => break, _ => {} } } - log::trace!("Main loop closed. Shutting down auxiliary loop."); + tracing::trace!("Main loop closed. Shutting down auxiliary and log loop."); set.shutdown().await; - - log::trace!("Main loop exited."); } async fn next_event(&mut self) -> Event { @@ -360,7 +319,7 @@ impl GlobalState { // Currently ignored }, LspNotification::DidCloseTextDocument(params) => { - handlers_state::did_close(params, &mut self.world, &self.auxiliary_event_tx)?; + handlers_state::did_close(params, &mut self.world)?; }, } }, @@ -368,7 +327,9 @@ impl GlobalState { LspMessage::Request(request, tx) => { match request { LspRequest::Initialize(params) => { - respond(tx, handlers_state::initialize(params, &mut self.lsp_state, &mut self.world), LspResponse::Initialize)?; + // Unwrap: `Initialize` method should only be called once. + let log_tx = self.log_tx.take().unwrap(); + respond(tx, handlers_state::initialize(params, &mut self.lsp_state, &mut self.world, log_tx), LspResponse::Initialize)?; }, LspRequest::Shutdown => { out = LoopControl::Shutdown; @@ -393,7 +354,7 @@ impl GlobalState { // TODO Make this threshold configurable by the client if loop_tick.elapsed() > std::time::Duration::from_millis(50) { - self.log_info(format!("Handler took {}ms", loop_tick.elapsed().as_millis())); + tracing::trace!("Handler took {}ms", loop_tick.elapsed().as_millis()); } Ok(out) @@ -422,16 +383,6 @@ impl GlobalState { respond(response_tx, handler(), into_lsp_response).and(Ok(None)) }); } - - fn log_info(&self, message: String) { - self.auxiliary_event_tx.log_info(message); - } - fn log_warn(&self, message: String) { - self.auxiliary_event_tx.log_warn(message); - } - fn log_error(&self, message: String) { - self.auxiliary_event_tx.log_error(message); - } } /// Respond to a request from the LSP @@ -508,7 +459,6 @@ impl AuxiliaryState { async fn start(mut self) -> ! { loop { match self.next_event().await { - AuxiliaryEvent::Log(level, message) => self.log(level, message).await, AuxiliaryEvent::SpawnedTask(handle) => self.tasks.push(Box::pin(handle)), AuxiliaryEvent::PublishDiagnostics(uri, diagnostics, version) => { self.client @@ -529,18 +479,11 @@ impl AuxiliaryState { Ok(Ok(Some(event))) => return event, // Otherwise relay any errors and loop back into select - Err(err) => self.log_error(format!("A task panicked:\n{err:?}")).await, - Ok(Err(err)) => self.log_error(format!("A task failed:\n{err:?}")).await, + Err(err) => tracing::error!("A task panicked:\n{err:?}"), + Ok(Err(err)) => tracing::error!("A task failed:\n{err:?}"), _ => (), }, } } } - - async fn log(&self, level: MessageType, message: String) { - self.client.log_message(level, message).await - } - async fn log_error(&self, message: String) { - self.client.log_message(MessageType::ERROR, message).await - } } diff --git a/crates/lsp/src/tower_lsp.rs b/crates/lsp/src/tower_lsp.rs index d0b0a717..5e824475 100644 --- a/crates/lsp/src/tower_lsp.rs +++ b/crates/lsp/src/tower_lsp.rs @@ -7,6 +7,8 @@ #![allow(deprecated)] +use strum::IntoStaticStr; + use tokio::io::{AsyncRead, AsyncWrite}; use tokio::sync::mpsc::unbounded_channel as tokio_unbounded_channel; use tower_lsp::jsonrpc::Result; @@ -17,7 +19,6 @@ use tower_lsp::LspService; use tower_lsp::{jsonrpc, ClientSocket}; use crate::handlers_ext::ViewFileParams; -use crate::main_loop::AuxiliaryEventSender; use crate::main_loop::Event; use crate::main_loop::GlobalState; use crate::main_loop::TokioUnboundedSender; @@ -43,7 +44,7 @@ pub(crate) enum LspMessage { ), } -#[derive(Debug)] +#[derive(Debug, IntoStaticStr)] pub(crate) enum LspNotification { Initialized(InitializedParams), DidChangeWorkspaceFolders(DidChangeWorkspaceFoldersParams), @@ -56,7 +57,7 @@ pub(crate) enum LspNotification { } #[allow(clippy::large_enum_variant)] -#[derive(Debug)] +#[derive(Debug, IntoStaticStr)] pub(crate) enum LspRequest { Initialize(InitializeParams), DocumentFormatting(DocumentFormattingParams), @@ -65,7 +66,7 @@ pub(crate) enum LspRequest { } #[allow(clippy::large_enum_variant)] -#[derive(Debug)] +#[derive(Debug, IntoStaticStr)] pub(crate) enum LspResponse { Initialize(InitializeResult), DocumentFormatting(Option>), @@ -73,15 +74,81 @@ pub(crate) enum LspResponse { AirViewFile(String), } +impl std::fmt::Display for LspNotification { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + f.write_str(self.into()) + } +} +impl std::fmt::Display for LspRequest { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + f.write_str(self.into()) + } +} +impl std::fmt::Display for LspResponse { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + f.write_str(self.into()) + } +} + +impl LspNotification { + fn trace(&self) -> TraceLspNotification { + TraceLspNotification { inner: self } + } +} +impl LspRequest { + fn trace(&self) -> TraceLspRequest { + TraceLspRequest { inner: self } + } +} +impl LspResponse { + fn trace(&self) -> TraceLspResponse { + TraceLspResponse { inner: self } + } +} + +struct TraceLspNotification<'a> { + inner: &'a LspNotification, +} +struct TraceLspRequest<'a> { + inner: &'a LspRequest, +} +struct TraceLspResponse<'a> { + inner: &'a LspResponse, +} + +impl std::fmt::Debug for TraceLspNotification<'_> { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + match self.inner { + LspNotification::DidOpenTextDocument(params) => { + // Ignore the document itself in trace logs + f.debug_tuple(self.inner.into()) + .field(¶ms.text_document.uri) + .field(¶ms.text_document.version) + .field(¶ms.text_document.language_id) + .finish() + } + _ => std::fmt::Debug::fmt(self.inner, f), + } + } +} + +impl std::fmt::Debug for TraceLspRequest<'_> { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + std::fmt::Debug::fmt(self.inner, f) + } +} + +impl std::fmt::Debug for TraceLspResponse<'_> { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + std::fmt::Debug::fmt(self.inner, f) + } +} + #[derive(Debug)] struct Backend { /// Channel for communication with the main loop. events_tx: TokioUnboundedSender, - /// Channel for communication with the auxiliary loop. - /// Used for latency sensitive logging. - auxiliary_event_tx: AuxiliaryEventSender, - /// Handle to main loop. Drop it to cancel the loop, all associated tasks, /// and drop all owned state. _main_loop: tokio::task::JoinSet<()>, @@ -89,7 +156,8 @@ struct Backend { impl Backend { async fn request(&self, request: LspRequest) -> anyhow::Result { - self.log_info(format!("Incoming: {request:#?}")); + tracing::info!("Incoming: {request}"); + tracing::trace!("Incoming (debug):\n{request:#?}", request = request.trace()); let (response_tx, mut response_rx) = tokio_unbounded_channel::>(); @@ -100,14 +168,19 @@ impl Backend { .unwrap(); // Wait for response from main loop - let out = response_rx.recv().await.unwrap()?; + let response = response_rx.recv().await.unwrap()?; - self.log_info(format!("Outgoing {out:#?}")); - Ok(out) + tracing::info!("Outgoing: {response}"); + tracing::trace!( + "Outgoing (debug):\n{response:#?}", + response = response.trace() + ); + Ok(response) } fn notify(&self, notif: LspNotification) { - self.log_info(format!("Incoming: {notif:#?}")); + tracing::info!("Incoming: {notif}"); + tracing::trace!("Incoming (debug):\n{notif:#?}", notif = notif.trace()); // Relay notification to main loop self.events_tx @@ -121,10 +194,6 @@ impl Backend { LspResponse::AirViewFile ) } - - fn log_info(&self, message: String) { - self.auxiliary_event_tx.log_info(message); - } } #[tower_lsp::async_trait] @@ -188,27 +257,20 @@ where I: AsyncRead + Unpin, O: AsyncWrite, { - log::trace!("Starting LSP"); - let (service, socket) = new_lsp(); let server = tower_lsp::Server::new(read, write, socket); server.serve(service).await; - - log::trace!("LSP exiting gracefully.",); } fn new_lsp() -> (LspService, ClientSocket) { let init = |client: Client| { - let state = GlobalState::new(client); - let events_tx = state.events_tx(); - let auxiliary_event_tx = state.auxiliary_event_tx(); + let (state, events_tx) = GlobalState::new(client); // Start main loop and hold onto the handle that keeps it alive let main_loop = state.start(); Backend { events_tx, - auxiliary_event_tx, _main_loop: main_loop, } }; diff --git a/crates/lsp_test/src/lsp_client.rs b/crates/lsp_test/src/lsp_client.rs index c19047d6..4d086590 100644 --- a/crates/lsp_test/src/lsp_client.rs +++ b/crates/lsp_test/src/lsp_client.rs @@ -11,6 +11,7 @@ use std::future::Future; use tokio::io::{AsyncRead, AsyncWrite}; use tokio::io::{ReadHalf, SimplexStream, WriteHalf}; use tokio_util::codec::{FramedRead, FramedWrite}; +use tower_lsp::lsp_types::ClientInfo; use tower_lsp::{jsonrpc, lsp_types}; use crate::tower_lsp::codec::LanguageServerCodec; @@ -87,9 +88,22 @@ impl TestClient { pub async fn initialize(&mut self) -> i64 { let params: Option = std::mem::take(&mut self.init_params); let params = params.unwrap_or_default(); + let params = Self::with_client_info(params); self.request::(params).await } + // Regardless of how we got the params, ensure the client name is set to + // `AirTestClient` so we can recognize it when we set up global logging. + fn with_client_info( + mut init_params: lsp_types::InitializeParams, + ) -> lsp_types::InitializeParams { + init_params.client_info = Some(ClientInfo { + name: String::from("AirTestClient"), + version: None, + }); + init_params + } + pub fn with_initialize_params(&mut self, init_params: lsp_types::InitializeParams) { self.init_params = Some(init_params); } diff --git a/crates/lsp_test/src/tower_lsp/codec.rs b/crates/lsp_test/src/tower_lsp/codec.rs index 5c1068c2..38f2af83 100644 --- a/crates/lsp_test/src/tower_lsp/codec.rs +++ b/crates/lsp_test/src/tower_lsp/codec.rs @@ -17,7 +17,7 @@ use bytes::buf::BufMut; use bytes::{Buf, BytesMut}; use memchr::memmem; use serde::{de::DeserializeOwned, Serialize}; -use tracing::{trace, warn}; +use tracing::warn; use tokio_util::codec::{Decoder, Encoder}; @@ -120,7 +120,7 @@ impl Encoder for LanguageServerCodec { fn encode(&mut self, item: T, dst: &mut BytesMut) -> Result<(), Self::Error> { let msg = serde_json::to_string(&item)?; - trace!("-> {}", msg); + // trace!("-> {}", msg); // Reserve just enough space to hold the `Content-Length: ` and `\r\n\r\n` constants, // the length of the message, and the message body. @@ -160,7 +160,7 @@ impl Decoder for LanguageServerCodec { let result = if message.is_empty() { Ok(None) } else { - trace!("<- {}", message); + // trace!("<- {}", message); match serde_json::from_str(message) { Ok(parsed) => Ok(Some(parsed)), Err(err) => Err(err.into()), diff --git a/justfile b/justfile index 0ae38573..818c4c0b 100644 --- a/justfile +++ b/justfile @@ -6,13 +6,18 @@ gen-formatter: gen-grammar: cargo run -p xtask_codegen -- grammar r -# Run the parser and formatter tests +# Run the tests test: - cargo test -p air_r_parser - cargo test -p air_r_formatter + cargo test + +# Run the tests in verbose mode +# `--nocapture` to see our own `tracing` logs +# `--test-threads 1` to ensure `tracing` logs aren't interleaved +test-verbose: + cargo test -- --nocapture --test-threads 1 # Run the quick formatter test -quick: +test-quick: cargo test --package air_r_formatter --test quick_test -- quick_test --exact --show-output --ignored # Creates a new crate