Unnamed repository; edit this file 'description' to name the repository.
Merge #9906
9906: switch `log` crate to `tracing` r=lnicola a=dzvon
Fixes #9274
1. Replace `log` crate with `tracing` of every crate that depend on `log`.
2. Change all `log` record macro with `tracing`.
3. Add `LoggerFormatter` make output format be the same as original.
Co-authored-by: Dezhi Wu <[email protected]>
48 files changed, 276 insertions, 238 deletions
diff --git a/Cargo.lock b/Cargo.lock index 1d4ad30298..3854c35cae 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -325,15 +325,6 @@ dependencies = [ ] [[package]] -name = "env_logger" -version = "0.9.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "0b2cf0344971ee6c64c31be0d530793fba457d322dfec2810c453d0ef228f9c3" -dependencies = [ - "log", -] - -[[package]] name = "expect-test" version = "1.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" @@ -380,12 +371,12 @@ dependencies = [ "cargo_metadata", "crossbeam-channel", "jod-thread", - "log", "paths", "serde", "serde_json", "stdx", "toolchain", + "tracing", ] [[package]] @@ -462,7 +453,6 @@ dependencies = [ "hir_ty", "indexmap", "itertools", - "log", "once_cell", "profile", "rustc-hash", @@ -490,7 +480,6 @@ dependencies = [ "itertools", "la-arena", "limit", - "log", "mbe", "once_cell", "profile", @@ -499,6 +488,7 @@ dependencies = [ "stdx", "syntax", "test_utils", + "tracing", "tt", ] @@ -514,13 +504,13 @@ dependencies = [ "itertools", "la-arena", "limit", - "log", "mbe", "parser", "profile", "rustc-hash", "syntax", "test_utils", + "tracing", "tt", ] @@ -541,7 +531,6 @@ dependencies = [ "itertools", "la-arena", "limit", - "log", "once_cell", "profile", "rustc-hash", @@ -581,7 +570,6 @@ dependencies = [ "ide_ssr", "indexmap", "itertools", - "log", "oorandom", "profile", "pulldown-cmark", @@ -591,6 +579,7 @@ dependencies = [ "syntax", "test_utils", "text_edit", + "tracing", "url", ] @@ -625,7 +614,6 @@ dependencies = [ "hir", "ide_db", "itertools", - "log", "once_cell", "profile", "rustc-hash", @@ -634,6 +622,7 @@ dependencies = [ "syntax", "test_utils", "text_edit", + "tracing", "xshell", ] @@ -649,7 +638,6 @@ dependencies = [ "hir", "itertools", "limit", - "log", "once_cell", "profile", "rayon", @@ -658,6 +646,7 @@ dependencies = [ "syntax", "test_utils", "text_edit", + "tracing", ] [[package]] @@ -889,7 +878,6 @@ version = "0.0.0" dependencies = [ "cov-mark", "expect-test", - "log", "parser", "profile", "rustc-hash", @@ -897,6 +885,7 @@ dependencies = [ "stdx", "syntax", "test_utils", + "tracing", "tt", ] @@ -1121,7 +1110,6 @@ version = "0.0.0" dependencies = [ "crossbeam-channel", "jod-thread", - "log", "memmap2", "object", "paths", @@ -1130,6 +1118,7 @@ dependencies = [ "serde_json", "snap", "stdx", + "tracing", "tt", ] @@ -1188,7 +1177,6 @@ dependencies = [ "cfg", "expect-test", "la-arena", - "log", "paths", "profile", "rustc-hash", @@ -1197,6 +1185,7 @@ dependencies = [ "serde_json", "stdx", "toolchain", + "tracing", ] [[package]] @@ -1308,7 +1297,6 @@ dependencies = [ "cfg", "crossbeam-channel", "dissimilar", - "env_logger", "expect-test", "flycheck", "hir", @@ -1319,7 +1307,6 @@ dependencies = [ "ide_ssr", "itertools", "jod-thread", - "log", "lsp-server", "lsp-types", "mbe", @@ -1343,6 +1330,7 @@ dependencies = [ "tikv-jemallocator", "toolchain", "tracing", + "tracing-log", "tracing-subscriber", "tracing-tree", "tt", @@ -1737,6 +1725,7 @@ dependencies = [ "thread_local", "tracing", "tracing-core", + "tracing-log", ] [[package]] @@ -1838,10 +1827,10 @@ version = "0.0.0" dependencies = [ "crossbeam-channel", "jod-thread", - "log", "notify", "paths", "rustc-hash", + "tracing", "vfs", "walkdir", ] diff --git a/crates/flycheck/Cargo.toml b/crates/flycheck/Cargo.toml index 8e0ef8f6d6..83624b494e 100644 --- a/crates/flycheck/Cargo.toml +++ b/crates/flycheck/Cargo.toml @@ -10,7 +10,7 @@ doctest = false [dependencies] crossbeam-channel = "0.5.0" -log = "0.4.8" +tracing = "0.1" cargo_metadata = "0.14" serde = { version = "1.0.106", features = ["derive"] } serde_json = "1.0.48" diff --git a/crates/flycheck/src/lib.rs b/crates/flycheck/src/lib.rs index 6a3b4a45a6..36604b81cb 100644 --- a/crates/flycheck/src/lib.rs +++ b/crates/flycheck/src/lib.rs @@ -163,7 +163,7 @@ impl FlycheckActor { self.cancel_check_process(); let mut command = self.check_command(); - log::info!("restart flycheck {:?}", command); + tracing::info!("restart flycheck {:?}", command); command.stdout(Stdio::piped()).stderr(Stdio::null()).stdin(Stdio::null()); if let Ok(child) = command.spawn().map(JodChild) { self.cargo_handle = Some(CargoHandle::spawn(child)); @@ -176,7 +176,7 @@ impl FlycheckActor { let cargo_handle = self.cargo_handle.take().unwrap(); let res = cargo_handle.join(); if res.is_err() { - log::error!( + tracing::error!( "Flycheck failed to run the following command: {:?}", self.check_command() ) @@ -319,7 +319,7 @@ impl CargoActor { let message = match message { Ok(message) => message, Err(err) => { - log::error!("Invalid json from cargo check, ignoring ({})", err); + tracing::error!("Invalid json from cargo check, ignoring ({})", err); continue; } }; diff --git a/crates/hir/Cargo.toml b/crates/hir/Cargo.toml index b9561e6f9e..ea1afb46d6 100644 --- a/crates/hir/Cargo.toml +++ b/crates/hir/Cargo.toml @@ -9,7 +9,6 @@ edition = "2018" doctest = false [dependencies] -log = "0.4.8" rustc-hash = "1.1.0" either = "1.5.3" arrayvec = "0.7" diff --git a/crates/hir_def/Cargo.toml b/crates/hir_def/Cargo.toml index 09a9fb27ba..f5e60a4f54 100644 --- a/crates/hir_def/Cargo.toml +++ b/crates/hir_def/Cargo.toml @@ -11,7 +11,7 @@ doctest = false [dependencies] cov-mark = "2.0.0-pre.1" dashmap = { version = "4.0.2", features = ["raw-api"] } -log = "0.4.8" +tracing = "0.1" once_cell = "1.3.1" rustc-hash = "1.1.0" either = "1.5.3" diff --git a/crates/hir_def/src/body.rs b/crates/hir_def/src/body.rs index 81956f35d6..5320a96bc5 100644 --- a/crates/hir_def/src/body.rs +++ b/crates/hir_def/src/body.rs @@ -135,7 +135,7 @@ impl Expander { None => { // Only `None` if the macro expansion produced no usable AST. if err.is_none() { - log::warn!("no error despite `parse_or_expand` failing"); + tracing::warn!("no error despite `parse_or_expand` failing"); } return Ok(ExpandResult::only_err(err.unwrap_or_else(|| { @@ -152,7 +152,7 @@ impl Expander { } }; - log::debug!("macro expansion {:#?}", node.syntax()); + tracing::debug!("macro expansion {:#?}", node.syntax()); self.recursion_limit += 1; let mark = Mark { diff --git a/crates/hir_def/src/nameres/collector.rs b/crates/hir_def/src/nameres/collector.rs index efedbb0ee2..209eedb005 100644 --- a/crates/hir_def/src/nameres/collector.rs +++ b/crates/hir_def/src/nameres/collector.rs @@ -64,7 +64,7 @@ pub(super) fn collect_defs( if block.is_none() { // populate external prelude for dep in &crate_graph[def_map.krate].dependencies { - log::debug!("crate dep {:?} -> {:?}", dep.name, dep.crate_id); + tracing::debug!("crate dep {:?} -> {:?}", dep.name, dep.crate_id); let dep_def_map = db.crate_def_map(dep.crate_id); def_map .extern_prelude @@ -358,7 +358,7 @@ impl DefCollector<'_> { i += 1; if FIXED_POINT_LIMIT.check(i).is_err() { - log::error!("name resolution is stuck"); + tracing::error!("name resolution is stuck"); break 'outer; } } @@ -510,7 +510,7 @@ impl DefCollector<'_> { return; } _ => { - log::debug!( + tracing::debug!( "could not resolve prelude path `{}` to module (resolved to {:?})", path, per_ns.types @@ -654,7 +654,7 @@ impl DefCollector<'_> { current_module_id: LocalModuleId, extern_crate: &item_tree::ExternCrate, ) { - log::debug!( + tracing::debug!( "importing macros from extern crate: {:?} ({:?})", extern_crate, self.def_map.edition, @@ -718,7 +718,7 @@ impl DefCollector<'_> { } fn resolve_import(&self, module_id: LocalModuleId, import: &Import) -> PartialResolvedImport { - log::debug!("resolving import: {:?} ({:?})", import, self.def_map.edition); + tracing::debug!("resolving import: {:?} ({:?})", import, self.def_map.edition); if import.is_extern_crate { let res = self.def_map.resolve_name_in_extern_prelude( self.db, @@ -794,7 +794,7 @@ impl DefCollector<'_> { def.macros = None; } - log::debug!("resolved import {:?} ({:?}) to {:?}", name, import, def); + tracing::debug!("resolved import {:?} ({:?}) to {:?}", name, import, def); // extern crates in the crate root are special-cased to insert entries into the extern prelude: rust-lang/rust#54658 if import.is_extern_crate && module_id == self.def_map.root { @@ -806,7 +806,7 @@ impl DefCollector<'_> { self.update(module_id, &[(name, def)], vis, ImportType::Named); } ImportKind::Glob => { - log::debug!("glob import: {:?}", import); + tracing::debug!("glob import: {:?}", import); match def.take_types() { Some(ModuleDefId::ModuleId(m)) => { if import.is_prelude { @@ -895,10 +895,10 @@ impl DefCollector<'_> { self.update(module_id, &resolutions, vis, ImportType::Glob); } Some(d) => { - log::debug!("glob import {:?} from non-module/enum {:?}", import, d); + tracing::debug!("glob import {:?} from non-module/enum {:?}", import, d); } None => { - log::debug!("glob import {:?} didn't resolve as type", import); + tracing::debug!("glob import {:?} didn't resolve as type", import); } } } @@ -947,7 +947,7 @@ impl DefCollector<'_> { let tr = match res.take_types() { Some(ModuleDefId::TraitId(tr)) => tr, Some(other) => { - log::debug!("non-trait `_` import of {:?}", other); + tracing::debug!("non-trait `_` import of {:?}", other); continue; } None => continue, @@ -1167,7 +1167,7 @@ impl DefCollector<'_> { ) { if EXPANSION_DEPTH_LIMIT.check(depth).is_err() { cov_mark::hit!(macro_expansion_overflow); - log::warn!("macro expansion is too deep"); + tracing::warn!("macro expansion is too deep"); return; } let file_id = macro_call_id.as_file(); @@ -1694,7 +1694,7 @@ impl ModCollector<'_, '_> { } else if self.is_builtin_or_registered_attr(&attr.path) { continue; } else { - log::debug!("non-builtin attribute {}", attr.path); + tracing::debug!("non-builtin attribute {}", attr.path); let ast_id = AstIdWithPath::new( self.file_id(), @@ -1768,7 +1768,7 @@ impl ModCollector<'_, '_> { } None => { // FIXME: diagnose - log::debug!("malformed derive: {:?}", attr); + tracing::debug!("malformed derive: {:?}", attr); } } } diff --git a/crates/hir_def/src/nameres/mod_resolution.rs b/crates/hir_def/src/nameres/mod_resolution.rs index 04427ffc80..031ff8b181 100644 --- a/crates/hir_def/src/nameres/mod_resolution.rs +++ b/crates/hir_def/src/nameres/mod_resolution.rs @@ -27,7 +27,7 @@ impl ModDir { fn child(&self, dir_path: DirPath, root_non_dir_owner: bool) -> Option<ModDir> { let depth = self.depth + 1; if MOD_DEPTH_LIMIT.check(depth as usize).is_err() { - log::error!("MOD_DEPTH_LIMIT exceeded"); + tracing::error!("MOD_DEPTH_LIMIT exceeded"); cov_mark::hit!(circular_mods); return None; } diff --git a/crates/hir_def/src/nameres/path_resolution.rs b/crates/hir_def/src/nameres/path_resolution.rs index 229f57d779..3beab9dcc3 100644 --- a/crates/hir_def/src/nameres/path_resolution.rs +++ b/crates/hir_def/src/nameres/path_resolution.rs @@ -116,7 +116,7 @@ impl DefMap { if self.block_id() != m.block { cov_mark::hit!(adjust_vis_in_block_def_map); vis = Visibility::Module(self.module_id(self.root())); - log::debug!("visibility {:?} points outside DefMap, adjusting to {:?}", m, vis); + tracing::debug!("visibility {:?} points outside DefMap, adjusting to {:?}", m, vis); } } @@ -204,7 +204,7 @@ impl DefMap { Some((idx, segment)) => (idx, segment), None => return ResolvePathResult::empty(ReachedFixedPoint::Yes), }; - log::debug!("resolving {:?} in crate root (+ extern prelude)", segment); + tracing::debug!("resolving {:?} in crate root (+ extern prelude)", segment); self.resolve_name_in_crate_root_or_extern_prelude(db, segment) } PathKind::Plain => { @@ -221,7 +221,7 @@ impl DefMap { let prefer_module = if path.segments().len() == 1 { shadow } else { BuiltinShadowMode::Module }; - log::debug!("resolving {:?} in module", segment); + tracing::debug!("resolving {:?} in module", segment); self.resolve_name_in_module(db, original_module, segment, prefer_module) } PathKind::Super(lvl) => { @@ -236,7 +236,11 @@ impl DefMap { PathKind::Super(lvl - i), path.segments().to_vec(), ); - log::debug!("`super` path: {} -> {} in parent map", path, new_path); + tracing::debug!( + "`super` path: {} -> {} in parent map", + path, + new_path + ); return block.parent.def_map(db).resolve_path_fp_with_macro( db, mode, @@ -246,7 +250,7 @@ impl DefMap { ); } None => { - log::debug!("super path in root module"); + tracing::debug!("super path in root module"); return ResolvePathResult::empty(ReachedFixedPoint::Yes); } }, @@ -270,7 +274,7 @@ impl DefMap { None => return ResolvePathResult::empty(ReachedFixedPoint::Yes), }; if let Some(def) = self.extern_prelude.get(segment) { - log::debug!("absolute path {:?} resolved to crate {:?}", path, def); + tracing::debug!("absolute path {:?} resolved to crate {:?}", path, def); PerNs::types(*def, Visibility::Public) } else { return ResolvePathResult::empty(ReachedFixedPoint::No); // extern crate declarations can add to the extern prelude @@ -299,7 +303,7 @@ impl DefMap { PathKind::Super(0), path.segments()[i..].iter().cloned(), ); - log::debug!("resolving {:?} in other crate", path); + tracing::debug!("resolving {:?} in other crate", path); let defp_map = module.def_map(db); let (def, s) = defp_map.resolve_path(db, module.local_id, &path, shadow); return ResolvePathResult::with( @@ -351,7 +355,7 @@ impl DefMap { s => { // could be an inherent method call in UFCS form // (`Struct::method`), or some other kind of associated item - log::debug!( + tracing::debug!( "path segment {:?} resolved to non-module {:?}, but is not last", segment, curr, diff --git a/crates/hir_def/src/nameres/proc_macro.rs b/crates/hir_def/src/nameres/proc_macro.rs index 3f095d623f..8c3454b31b 100644 --- a/crates/hir_def/src/nameres/proc_macro.rs +++ b/crates/hir_def/src/nameres/proc_macro.rs @@ -70,7 +70,7 @@ impl Attrs { } _ => { - log::trace!("malformed `#[proc_macro_derive]`: {}", derive); + tracing::trace!("malformed `#[proc_macro_derive]`: {}", derive); None } } diff --git a/crates/hir_expand/Cargo.toml b/crates/hir_expand/Cargo.toml index 743e807910..9cd2768106 100644 --- a/crates/hir_expand/Cargo.toml +++ b/crates/hir_expand/Cargo.toml @@ -10,7 +10,7 @@ doctest = false [dependencies] cov-mark = "2.0.0-pre.1" -log = "0.4.8" +tracing = "0.1" either = "1.5.3" rustc-hash = "1.0.0" la-arena = { version = "0.2.0", path = "../../lib/arena" } diff --git a/crates/hir_expand/src/builtin_derive.rs b/crates/hir_expand/src/builtin_derive.rs index 57a5fb4972..9ab61ce7ce 100644 --- a/crates/hir_expand/src/builtin_derive.rs +++ b/crates/hir_expand/src/builtin_derive.rs @@ -1,6 +1,6 @@ //! Builtin derives. -use log::debug; +use tracing::debug; use mbe::ExpandResult; use parser::FragmentKind; diff --git a/crates/hir_expand/src/db.rs b/crates/hir_expand/src/db.rs index 2fc8468faf..e990d5fce6 100644 --- a/crates/hir_expand/src/db.rs +++ b/crates/hir_expand/src/db.rs @@ -203,7 +203,7 @@ fn parse_macro_expansion( .collect::<Vec<_>>() .join("\n"); - log::warn!( + tracing::warn!( "fail on macro_parse: (reason: {:?} macro_call: {:#}) parents: {}", err, node.value, @@ -217,13 +217,13 @@ fn parse_macro_expansion( let fragment_kind = macro_fragment_kind(db, macro_file.macro_call_id); - log::debug!("expanded = {}", tt.as_debug_string()); - log::debug!("kind = {:?}", fragment_kind); + tracing::debug!("expanded = {}", tt.as_debug_string()); + tracing::debug!("kind = {:?}", fragment_kind); let (parse, rev_token_map) = match mbe::token_tree_to_syntax_node(&tt, fragment_kind) { Ok(it) => it, Err(err) => { - log::debug!( + tracing::debug!( "failed to parse expansion to {:?} = {}", fragment_kind, tt.as_debug_string() @@ -250,7 +250,7 @@ fn parse_macro_expansion( } } None => { - log::debug!("parse = {:?}", parse.syntax_node().kind()); + tracing::debug!("parse = {:?}", parse.syntax_node().kind()); ExpandResult { value: Some((parse, Arc::new(rev_token_map))), err: None } } } @@ -321,7 +321,7 @@ fn macro_def(db: &dyn AstDatabase, id: MacroDefId) -> Option<Arc<TokenExpander>> Ok(it) => it, Err(err) => { let name = macro_rules.name().map(|n| n.to_string()).unwrap_or_default(); - log::warn!("fail on macro_def parse ({}): {:?} {:#?}", name, err, tt); + tracing::warn!("fail on macro_def parse ({}): {:?} {:#?}", name, err, tt); return None; } }; @@ -334,7 +334,7 @@ fn macro_def(db: &dyn AstDatabase, id: MacroDefId) -> Option<Arc<TokenExpander>> Ok(it) => it, Err(err) => { let name = macro_def.name().map(|n| n.to_string()).unwrap_or_default(); - log::warn!("fail on macro_def parse ({}): {:?} {:#?}", name, err, tt); + tracing::warn!("fail on macro_def parse ({}): {:?} {:#?}", name, err, tt); return None; } }; diff --git a/crates/hir_expand/src/lib.rs b/crates/hir_expand/src/lib.rs index 3bbbb5722f..512cafe69d 100644 --- a/crates/hir_expand/src/lib.rs +++ b/crates/hir_expand/src/lib.rs @@ -561,7 +561,7 @@ impl<'a> InFile<&'a SyntaxNode> { Some(range) => { let original_file = range.file_id.original_file(db); if range.file_id != original_file.into() { - log::error!("Failed mapping up more for {:?}", range); + tracing::error!("Failed mapping up more for {:?}", range); } Some(FileRange { file_id: original_file, range: range.value }) } diff --git a/crates/hir_ty/Cargo.toml b/crates/hir_ty/Cargo.toml index 304dbb1b99..a3c07518e7 100644 --- a/crates/hir_ty/Cargo.toml +++ b/crates/hir_ty/Cargo.toml @@ -14,7 +14,7 @@ itertools = "0.10.0" arrayvec = "0.7" smallvec = "1.2.0" ena = "0.14.0" -log = "0.4.8" +tracing = "0.1" rustc-hash = "1.1.0" scoped-tls = "1" chalk-solve = { version = "0.70", default-features = false } diff --git a/crates/hir_ty/src/autoderef.rs b/crates/hir_ty/src/autoderef.rs index 0be337fc2d..8c18c6dfed 100644 --- a/crates/hir_ty/src/autoderef.rs +++ b/crates/hir_ty/src/autoderef.rs @@ -10,7 +10,7 @@ use chalk_ir::{cast::Cast, fold::Fold, interner::HasInterner, VariableKind}; use hir_def::lang_item::LangItemTarget; use hir_expand::name::name; use limit::Limit; -use log::{info, warn}; +use tracing::{info, warn}; use crate::{ db::HirDatabase, static_lifetime, AliasEq, AliasTy, BoundVar, Canonical, CanonicalVarKinds, diff --git a/crates/hir_ty/src/chalk_db.rs b/crates/hir_ty/src/chalk_db.rs index 333d934ed3..d26a0293db 100644 --- a/crates/hir_ty/src/chalk_db.rs +++ b/crates/hir_ty/src/chalk_db.rs @@ -3,7 +3,7 @@ use std::sync::Arc; use cov_mark::hit; -use log::debug; +use tracing::debug; use chalk_ir::{cast::Cast, fold::shift::Shift, CanonicalVarKinds}; use chalk_solve::rust_ir::{self, OpaqueTyDatumBound, WellKnownTrait}; diff --git a/crates/hir_ty/src/consteval.rs b/crates/hir_ty/src/consteval.rs index ab1afce081..0e323c3013 100644 --- a/crates/hir_ty/src/consteval.rs +++ b/crates/hir_ty/src/consteval.rs @@ -28,7 +28,10 @@ impl ConstExt for Const { chalk_ir::ConstValue::Concrete(..) => false, _ => { - log::error!("is_unknown was called on a non-concrete constant value! {:?}", self); + tracing::error!( + "is_unknown was called on a non-concrete constant value! {:?}", + self + ); true } } diff --git a/crates/hir_ty/src/traits.rs b/crates/hir_ty/src/traits.rs index b63dfafdf5..976c1308e7 100644 --- a/crates/hir_ty/src/traits.rs +++ b/crates/hir_ty/src/traits.rs @@ -81,7 +81,7 @@ pub(crate) fn trait_solve_query( GoalData::DomainGoal(DomainGoal::Holds(WhereClause::AliasEq(_))) => "alias_eq".to_string(), _ => "??".to_string(), }); - log::info!("trait_solve_query({:?})", goal.value.goal); + tracing::info!("trait_solve_query({:?})", goal.value.goal); if let GoalData::DomainGoal(DomainGoal::Holds(WhereClause::AliasEq(AliasEq { alias: AliasTy::Projection(projection_ty), @@ -106,7 +106,7 @@ fn solve( goal: &chalk_ir::UCanonical<chalk_ir::InEnvironment<chalk_ir::Goal<Interner>>>, ) -> Option<chalk_solve::Solution<Interner>> { let context = ChalkContext { db, krate }; - log::debug!("solve goal: {:?}", goal); + tracing::debug!("solve goal: {:?}", goal); let mut solver = create_chalk_solver(); let fuel = std::cell::Cell::new(CHALK_SOLVER_FUEL); @@ -116,7 +116,7 @@ fn solve( let remaining = fuel.get(); fuel.set(remaining - 1); if remaining == 0 { - log::debug!("fuel exhausted"); + tracing::debug!("fuel exhausted"); } remaining > 0 }; @@ -136,7 +136,7 @@ fn solve( solver.solve_limited(&context, goal, &should_continue) }; - log::debug!("solve({:?}) => {:?}", goal, solution); + tracing::debug!("solve({:?}) => {:?}", goal, solution); solution }; diff --git a/crates/ide/Cargo.toml b/crates/ide/Cargo.toml index 5e052a67ae..804002a4b3 100644 --- a/crates/ide/Cargo.toml +++ b/crates/ide/Cargo.toml @@ -13,7 +13,7 @@ cov-mark = "2.0.0-pre.1" either = "1.5.3" indexmap = "1.4.0" itertools = "0.10.0" -log = "0.4.8" +tracing = "0.1" rustc-hash = "1.1.0" oorandom = "11.1.2" pulldown-cmark-to-cmark = "6.0.0" diff --git a/crates/ide/src/display/navigation_target.rs b/crates/ide/src/display/navigation_target.rs index b8c14dc97b..4a0c0fcca9 100644 --- a/crates/ide/src/display/navigation_target.rs +++ b/crates/ide/src/display/navigation_target.rs @@ -353,7 +353,7 @@ impl TryToNav for hir::MacroDef { Either::Left(it) => it, Either::Right(it) => it, }; - log::debug!("nav target {:#?}", name_owner.syntax()); + tracing::debug!("nav target {:#?}", name_owner.syntax()); let mut res = NavigationTarget::from_named( db, src.as_ref().with_value(name_owner), diff --git a/crates/ide_completion/Cargo.toml b/crates/ide_completion/Cargo.toml index 447744da17..67c86216f1 100644 --- a/crates/ide_completion/Cargo.toml +++ b/crates/ide_completion/Cargo.toml @@ -11,7 +11,7 @@ doctest = false [dependencies] cov-mark = "2.0.0-pre.1" itertools = "0.10.0" -log = "0.4.8" +tracing = "0.1" rustc-hash = "1.1.0" either = "1.6.1" once_cell = "1.7" diff --git a/crates/ide_db/Cargo.toml b/crates/ide_db/Cargo.toml index f8a2cbef8d..981a58347a 100644 --- a/crates/ide_db/Cargo.toml +++ b/crates/ide_db/Cargo.toml @@ -10,7 +10,7 @@ doctest = false [dependencies] cov-mark = "2.0.0-pre.1" -log = "0.4.8" +tracing = "0.1" rayon = "1.5.0" fst = { version = "0.4", default-features = false } rustc-hash = "1.1.0" diff --git a/crates/ide_db/src/apply_change.rs b/crates/ide_db/src/apply_change.rs index 80252597d9..d9bf7c9cc7 100644 --- a/crates/ide_db/src/apply_change.rs +++ b/crates/ide_db/src/apply_change.rs @@ -20,7 +20,7 @@ impl RootDatabase { pub fn apply_change(&mut self, change: Change) { let _p = profile::span("RootDatabase::apply_change"); self.request_cancellation(); - log::info!("apply_change {:?}", change); + tracing::info!("apply_change {:?}", change); if let Some(roots) = &change.roots { let mut local_roots = FxHashSet::default(); let mut library_roots = FxHashSet::default(); diff --git a/crates/mbe/Cargo.toml b/crates/mbe/Cargo.toml index 411bb75dbc..1a522e9070 100644 --- a/crates/mbe/Cargo.toml +++ b/crates/mbe/Cargo.toml @@ -12,8 +12,8 @@ doctest = false cov-mark = "2.0.0-pre.1" rustc-hash = "1.1.0" smallvec = "1.2.0" -log = "0.4.8" expect-test = "1.1" +tracing = "0.1" syntax = { path = "../syntax", version = "0.0.0" } parser = { path = "../parser", version = "0.0.0" } diff --git a/crates/mbe/src/expander/transcriber.rs b/crates/mbe/src/expander/transcriber.rs index 4894e2a0c3..8140f25b06 100644 --- a/crates/mbe/src/expander/transcriber.rs +++ b/crates/mbe/src/expander/transcriber.rs @@ -174,7 +174,11 @@ fn expand_repeat( counter += 1; if counter == limit { - log::warn!("expand_tt in repeat pattern exceed limit => {:#?}\n{:#?}", template, ctx); + tracing::warn!( + "expand_tt in repeat pattern exceed limit => {:#?}\n{:#?}", + template, + ctx + ); return ExpandResult { value: Fragment::Tokens(Subtree::default().into()), err: Some(ExpandError::Other("Expand exceed limit".to_string())), diff --git a/crates/proc_macro_api/Cargo.toml b/crates/proc_macro_api/Cargo.toml index a0fd10441f..e59b903bc5 100644 --- a/crates/proc_macro_api/Cargo.toml +++ b/crates/proc_macro_api/Cargo.toml @@ -11,7 +11,7 @@ doctest = false [dependencies] serde = { version = "1.0", features = ["derive"] } serde_json = { version = "1.0", features = ["unbounded_depth"] } -log = "0.4.8" +tracing = "0.1" crossbeam-channel = "0.5.0" jod-thread = "0.1.1" memmap2 = "0.3.0" diff --git a/crates/proc_macro_api/src/msg.rs b/crates/proc_macro_api/src/msg.rs index fd10d87f08..04248e0447 100644 --- a/crates/proc_macro_api/src/msg.rs +++ b/crates/proc_macro_api/src/msg.rs @@ -93,7 +93,7 @@ fn read_json<'a>( // Some ill behaved macro try to use stdout for debugging // We ignore it here if !buf.starts_with('{') { - log::error!("proc-macro tried to print : {}", buf); + tracing::error!("proc-macro tried to print : {}", buf); continue; } @@ -102,7 +102,7 @@ fn read_json<'a>( } fn write_json(out: &mut impl Write, msg: &str) -> io::Result<()> { - log::debug!("> {}", msg); + tracing::debug!("> {}", msg); out.write_all(msg.as_bytes())?; out.write_all(b"\n")?; out.flush()?; diff --git a/crates/proc_macro_api/src/process.rs b/crates/proc_macro_api/src/process.rs index 79c749d55a..2fa5d65be2 100644 --- a/crates/proc_macro_api/src/process.rs +++ b/crates/proc_macro_api/src/process.rs @@ -54,7 +54,7 @@ impl ProcMacroProcessSrv { Ok(res) => res, Err(err) => { let result = self.process.child.try_wait(); - log::error!( + tracing::error!( "proc macro server crashed, server process state: {:?}, server request error: {:?}", result, err diff --git a/crates/project_model/Cargo.toml b/crates/project_model/Cargo.toml index 732e4952fa..cea2c16a63 100644 --- a/crates/project_model/Cargo.toml +++ b/crates/project_model/Cargo.toml @@ -9,7 +9,7 @@ edition = "2018" doctest = false [dependencies] -log = "0.4.8" +tracing = "0.1" rustc-hash = "1.1.0" cargo_metadata = "0.14" semver = "1" diff --git a/crates/project_model/src/cargo_workspace.rs b/crates/project_model/src/cargo_workspace.rs index 22cd4a7082..764784d770 100644 --- a/crates/project_model/src/cargo_workspace.rs +++ b/crates/project_model/src/cargo_workspace.rs @@ -283,7 +283,7 @@ impl CargoWorkspace { let meta = from_value::<PackageMetadata>(metadata.clone()).unwrap_or_default(); let is_member = ws_members.contains(id); let edition = edition.parse::<Edition>().unwrap_or_else(|err| { - log::error!("Failed to parse edition {}", err); + tracing::error!("Failed to parse edition {}", err); Edition::CURRENT }); @@ -322,7 +322,7 @@ impl CargoWorkspace { // https://github.com/rust-lang/cargo/issues/7841 // is fixed and hits stable (around 1.43-is probably?). None => { - log::error!("Node id do not match in cargo metadata, ignoring {}", node.id); + tracing::error!("Node id do not match in cargo metadata, ignoring {}", node.id); continue; } }; @@ -335,7 +335,7 @@ impl CargoWorkspace { let pkg = match pkg_by_id.get(&dep_node.pkg) { Some(&pkg) => pkg, None => { - log::error!( + tracing::error!( "Dep node id do not match in cargo metadata, ignoring {}", dep_node.pkg ); @@ -385,7 +385,7 @@ impl CargoWorkspace { fn rustc_discover_host_triple(cargo_toml: &ManifestPath) -> Option<String> { let mut rustc = Command::new(toolchain::rustc()); rustc.current_dir(cargo_toml.parent()).arg("-vV"); - log::debug!("Discovering host platform by {:?}", rustc); + tracing::debug!("Discovering host platform by {:?}", rustc); match utf8_stdout(rustc) { Ok(stdout) => { let field = "host: "; @@ -394,12 +394,12 @@ fn rustc_discover_host_triple(cargo_toml: &ManifestPath) -> Option<String> { Some(target.to_string()) } else { // If we fail to resolve the host platform, it's not the end of the world. - log::info!("rustc -vV did not report host platform, got:\n{}", stdout); + tracing::info!("rustc -vV did not report host platform, got:\n{}", stdout); None } } Err(e) => { - log::warn!("Failed to discover host platform: {}", e); + tracing::warn!("Failed to discover host platform: {}", e); None } } @@ -412,7 +412,7 @@ fn cargo_config_build_target(cargo_toml: &ManifestPath) -> Option<String> { .args(&["-Z", "unstable-options", "config", "get", "build.target"]) .env("RUSTC_BOOTSTRAP", "1"); // if successful we receive `build.target = "target-triple"` - log::debug!("Discovering cargo config target by {:?}", cargo_config); + tracing::debug!("Discovering cargo config target by {:?}", cargo_config); match utf8_stdout(cargo_config) { Ok(stdout) => stdout .strip_prefix("build.target = \"") diff --git a/crates/project_model/src/rustc_cfg.rs b/crates/project_model/src/rustc_cfg.rs index 2755e5768f..515fe20031 100644 --- a/crates/project_model/src/rustc_cfg.rs +++ b/crates/project_model/src/rustc_cfg.rs @@ -20,7 +20,7 @@ pub(crate) fn get(cargo_toml: Option<&ManifestPath>, target: Option<&str>) -> Ve match get_rust_cfgs(cargo_toml, target) { Ok(rustc_cfgs) => res.extend(rustc_cfgs.lines().map(|it| it.parse().unwrap())), - Err(e) => log::error!("failed to get rustc cfgs: {:#}", e), + Err(e) => tracing::error!("failed to get rustc cfgs: {:#}", e), } res diff --git a/crates/project_model/src/sysroot.rs b/crates/project_model/src/sysroot.rs index 946b79d176..6c17492948 100644 --- a/crates/project_model/src/sysroot.rs +++ b/crates/project_model/src/sysroot.rs @@ -54,7 +54,7 @@ impl Sysroot { } pub fn discover(dir: &AbsPath) -> Result<Sysroot> { - log::debug!("Discovering sysroot for {}", dir.display()); + tracing::debug!("Discovering sysroot for {}", dir.display()); let sysroot_dir = discover_sysroot_dir(dir)?; let sysroot_src_dir = discover_sysroot_src_dir(&sysroot_dir, dir)?; let res = Sysroot::load(sysroot_src_dir)?; @@ -62,7 +62,7 @@ impl Sysroot { } pub fn discover_rustc(cargo_toml: &ManifestPath) -> Option<ManifestPath> { - log::debug!("Discovering rustc source for {}", cargo_toml.display()); + tracing::debug!("Discovering rustc source for {}", cargo_toml.display()); let current_dir = cargo_toml.parent(); discover_sysroot_dir(current_dir).ok().and_then(|sysroot_dir| get_rustc_src(&sysroot_dir)) } @@ -132,7 +132,7 @@ impl Sysroot { fn discover_sysroot_dir(current_dir: &AbsPath) -> Result<AbsPathBuf> { let mut rustc = Command::new(toolchain::rustc()); rustc.current_dir(current_dir).args(&["--print", "sysroot"]); - log::debug!("Discovering sysroot by {:?}", rustc); + tracing::debug!("Discovering sysroot by {:?}", rustc); let stdout = utf8_stdout(rustc)?; Ok(AbsPathBuf::assert(PathBuf::from(stdout))) } @@ -146,10 +146,10 @@ fn discover_sysroot_src_dir( .map_err(|path| format_err!("RUST_SRC_PATH must be absolute: {}", path.display()))?; let core = path.join("core"); if fs::metadata(&core).is_ok() { - log::debug!("Discovered sysroot by RUST_SRC_PATH: {}", path.display()); + tracing::debug!("Discovered sysroot by RUST_SRC_PATH: {}", path.display()); return Ok(path); } - log::debug!("RUST_SRC_PATH is set, but is invalid (no core: {:?}), ignoring", core); + tracing::debug!("RUST_SRC_PATH is set, but is invalid (no core: {:?}), ignoring", core); } get_rust_src(sysroot_path) @@ -174,7 +174,7 @@ try installing the Rust source the same way you installed rustc", fn get_rustc_src(sysroot_path: &AbsPath) -> Option<ManifestPath> { let rustc_src = sysroot_path.join("lib/rustlib/rustc-src/rust/compiler/rustc/Cargo.toml"); let rustc_src = ManifestPath::try_from(rustc_src).ok()?; - log::debug!("Checking for rustc source code: {}", rustc_src.display()); + tracing::debug!("Checking for rustc source code: {}", rustc_src.display()); if fs::metadata(&rustc_src).is_ok() { Some(rustc_src) } else { @@ -185,7 +185,10 @@ fn get_rustc_src(sysroot_path: &AbsPath) -> Option<ManifestPath> { fn get_rust_src(sysroot_path: &AbsPath) -> Option<AbsPathBuf> { // Try the new path first since the old one still exists. let rust_src = sysroot_path.join("lib/rustlib/src/rust"); - log::debug!("Checking sysroot (looking for `library` and `src` dirs): {}", rust_src.display()); + tracing::debug!( + "Checking sysroot (looking for `library` and `src` dirs): {}", + rust_src.display() + ); ["library", "src"].iter().map(|it| rust_src.join(it)).find(|it| fs::metadata(it).is_ok()) } diff --git a/crates/project_model/src/workspace.rs b/crates/project_model/src/workspace.rs index d911209b07..8e4aa0506f 100644 --- a/crates/project_model/src/workspace.rs +++ b/crates/project_model/src/workspace.rs @@ -384,9 +384,9 @@ impl ProjectWorkspace { } }; if crate_graph.patch_cfg_if() { - log::debug!("Patched std to depend on cfg-if") + tracing::debug!("Patched std to depend on cfg-if") } else { - log::debug!("Did not patch std to depend on cfg-if") + tracing::debug!("Did not patch std to depend on cfg-if") } crate_graph } @@ -623,7 +623,7 @@ fn detached_files_to_crate_graph( let file_id = match load(detached_file) { Some(file_id) => file_id, None => { - log::error!("Failed to load detached file {:?}", detached_file); + tracing::error!("Failed to load detached file {:?}", detached_file); continue; } }; @@ -847,7 +847,7 @@ fn sysroot_to_crate_graph( fn add_dep(graph: &mut CrateGraph, from: CrateId, name: CrateName, to: CrateId) { if let Err(err) = graph.add_dep(from, name, to) { - log::error!("{}", err) + tracing::error!("{}", err) } } diff --git a/crates/rust-analyzer/Cargo.toml b/crates/rust-analyzer/Cargo.toml index d194879f04..a81581894f 100644 --- a/crates/rust-analyzer/Cargo.toml +++ b/crates/rust-analyzer/Cargo.toml @@ -20,10 +20,8 @@ path = "src/bin/main.rs" anyhow = "1.0.26" crossbeam-channel = "0.5.0" dissimilar = "1.0.2" -env_logger = { version = "0.9", default-features = false } itertools = "0.10.0" jod-thread = "0.1.0" -log = "0.4.8" lsp-types = { version = "0.89.0", features = ["proposed"] } parking_lot = "0.11.0" xflags = "0.2.1" @@ -36,7 +34,8 @@ rayon = "1.5" mimalloc = { version = "0.1.19", default-features = false, optional = true } lsp-server = "0.5.1" tracing = "0.1" -tracing-subscriber = { version = "0.2", default-features = false, features = ["env-filter", "registry"] } +tracing-subscriber = { version = "0.2", default-features = false, features = ["env-filter", "registry", "fmt", "tracing-log"] } +tracing-log = "0.1.2" tracing-tree = { version = "0.1.4" } always-assert = "0.1" diff --git a/crates/rust-analyzer/src/bin/logger.rs b/crates/rust-analyzer/src/bin/logger.rs index f8f57b2aa7..9a31dec7e3 100644 --- a/crates/rust-analyzer/src/bin/logger.rs +++ b/crates/rust-analyzer/src/bin/logger.rs @@ -1,88 +1,142 @@ -//! Simple logger that logs either to stderr or to a file, using `env_logger` -//! filter syntax. Amusingly, there's no crates.io crate that can do this and -//! only this. +//! Simple logger that logs either to stderr or to a file, using `tracing_subscriber` +//! filter syntax and `tracing_appender` for non blocking output. use std::{ + fmt::{self, Write}, fs::File, - io::{self, BufWriter, Write}, + io, + sync::Arc, }; -use env_logger::filter::{Builder, Filter}; -use log::{Log, Metadata, Record}; -use parking_lot::Mutex; +use rust_analyzer::Result; +use tracing::{level_filters::LevelFilter, Event, Subscriber}; +use tracing_log::NormalizeEvent; +use tracing_subscriber::{ + fmt::{writer::BoxMakeWriter, FmtContext, FormatEvent, FormatFields, FormattedFields}, + layer::SubscriberExt, + registry::LookupSpan, + util::SubscriberInitExt, + EnvFilter, Registry, +}; +use tracing_tree::HierarchicalLayer; pub(crate) struct Logger { - filter: Filter, - file: Option<Mutex<BufWriter<File>>>, - no_buffering: bool, + filter: EnvFilter, + file: Option<File>, } impl Logger { - pub(crate) fn new(log_file: Option<File>, no_buffering: bool, filter: Option<&str>) -> Logger { - let filter = { - let mut builder = Builder::new(); - if let Some(filter) = filter { - builder.parse(filter); - } - builder.build() - }; + pub(crate) fn new(file: Option<File>, filter: Option<&str>) -> Logger { + let filter = filter.map_or(EnvFilter::default(), |dirs| EnvFilter::new(dirs)); - let file = log_file.map(|it| Mutex::new(BufWriter::new(it))); - - Logger { filter, file, no_buffering } + Logger { filter, file } } - pub(crate) fn install(self) { - let max_level = self.filter.filter(); - let _ = log::set_boxed_logger(Box::new(self)).map(|()| log::set_max_level(max_level)); - } -} + pub(crate) fn install(self) -> Result<()> { + // The meaning of CHALK_DEBUG I suspected is to tell chalk crates + // (i.e. chalk-solve, chalk-ir, chalk-recursive) how to filter tracing + // logs. But now we can only have just one filter, which means we have to + // merge chalk filter to our main filter (from RA_LOG env). + // + // The acceptable syntax of CHALK_DEBUG is `target[span{field=value}]=level`. + // As the value should only affect chalk crates, we'd better mannually + // specify the target. And for simplicity, CHALK_DEBUG only accept the value + // that specify level. + let chalk_level_dir = std::env::var("CHALK_DEBUG") + .map(|val| { + val.parse::<LevelFilter>().expect( + "invalid CHALK_DEBUG value, expect right log level (like debug or trace)", + ) + }) + .ok(); -impl Log for Logger { - fn enabled(&self, metadata: &Metadata) -> bool { - self.filter.enabled(metadata) - } + let chalk_layer = HierarchicalLayer::default() + .with_indent_lines(true) + .with_ansi(false) + .with_indent_amount(2) + .with_writer(std::io::stderr); + + let writer = match self.file { + Some(file) => BoxMakeWriter::new(Arc::new(file)), + None => BoxMakeWriter::new(io::stderr), + }; + let ra_fmt_layer = + tracing_subscriber::fmt::layer().event_format(LoggerFormatter).with_writer(writer); - fn log(&self, record: &Record) { - if !self.filter.matches(record) { - return; - } - - match &self.file { - Some(w) => { - let mut writer = w.lock(); - let _ = writeln!( - writer, - "[{} {}] {}", - record.level(), - record.module_path().unwrap_or_default(), - record.args(), - ); - - if self.no_buffering { - let _ = writer.flush(); - } + match chalk_level_dir { + Some(val) => { + Registry::default() + .with( + self.filter + .add_directive(format!("chalk_solve={}", val).parse()?) + .add_directive(format!("chalk_ir={}", val).parse()?) + .add_directive(format!("chalk_recursive={}", val).parse()?), + ) + .with(ra_fmt_layer) + .with(chalk_layer) + .init(); } None => { - let message = format!( - "[{} {}] {}\n", - record.level(), - record.module_path().unwrap_or_default(), - record.args(), - ); - eprint!("{}", message); + Registry::default().with(self.filter).with(ra_fmt_layer).init(); } }; + + Ok(()) } +} - fn flush(&self) { - match &self.file { - Some(w) => { - let _ = w.lock().flush(); - } - None => { - let _ = io::stderr().flush(); +#[derive(Debug)] +struct LoggerFormatter; + +impl<S, N> FormatEvent<S, N> for LoggerFormatter +where + S: Subscriber + for<'a> LookupSpan<'a>, + N: for<'a> FormatFields<'a> + 'static, +{ + fn format_event( + &self, + ctx: &FmtContext<'_, S, N>, + writer: &mut dyn Write, + event: &Event<'_>, + ) -> fmt::Result { + // Write level and target + let level = *event.metadata().level(); + + // If this event is issued from `log` crate, then the value of target is + // always "log". `tracing-log` has hard coded it for some reason, so we + // need to extract it using `normalized_metadata` method which is part of + // `tracing_log::NormalizeEvent`. + let target = match event.normalized_metadata() { + // This event is issued from `log` crate + Some(log) => log.target(), + None => event.metadata().target(), + }; + write!(writer, "[{} {}] ", level, target)?; + + // Write spans and fields of each span + ctx.visit_spans(|span| { + write!(writer, "{}", span.name())?; + + let ext = span.extensions(); + + // `FormattedFields` is a a formatted representation of the span's + // fields, which is stored in its extensions by the `fmt` layer's + // `new_span` method. The fields will have been formatted + // by the same field formatter that's provided to the event + // formatter in the `FmtContext`. + let fields = &ext.get::<FormattedFields<N>>().expect("will never be `None`"); + + if !fields.is_empty() { + write!(writer, "{{{}}}", fields)?; } - } + write!(writer, ": ")?; + + Ok(()) + })?; + + // Write fields on the event + ctx.field_format().format_fields(writer, event)?; + + writeln!(writer) } } diff --git a/crates/rust-analyzer/src/bin/main.rs b/crates/rust-analyzer/src/bin/main.rs index ace07cc50d..f7e9415cc0 100644 --- a/crates/rust-analyzer/src/bin/main.rs +++ b/crates/rust-analyzer/src/bin/main.rs @@ -35,7 +35,7 @@ fn main() { } if let Err(err) = try_main() { - log::error!("Unexpected error: {}", err); + tracing::error!("Unexpected error: {}", err); eprintln!("{}", err); process::exit(101); } @@ -60,7 +60,7 @@ fn try_main() -> Result<()> { log_file = Some(Path::new(env_log_file)); } - setup_logging(log_file, flags.no_log_buffering)?; + setup_logging(log_file)?; let verbosity = flags.verbosity(); match flags.subcommand { @@ -91,7 +91,7 @@ fn try_main() -> Result<()> { Ok(()) } -fn setup_logging(log_file: Option<&Path>, no_buffering: bool) -> Result<()> { +fn setup_logging(log_file: Option<&Path>) -> Result<()> { env::set_var("RUST_BACKTRACE", "short"); let log_file = match log_file { @@ -104,42 +104,20 @@ fn setup_logging(log_file: Option<&Path>, no_buffering: bool) -> Result<()> { None => None, }; let filter = env::var("RA_LOG").ok(); - logger::Logger::new(log_file, no_buffering, filter.as_deref()).install(); - - tracing_setup::setup_tracing()?; + logger::Logger::new(log_file, filter.as_deref()).install()?; profile::init(); Ok(()) } -mod tracing_setup { - use tracing::subscriber; - use tracing_subscriber::layer::SubscriberExt; - use tracing_subscriber::EnvFilter; - use tracing_subscriber::Registry; - use tracing_tree::HierarchicalLayer; - - pub(crate) fn setup_tracing() -> super::Result<()> { - let filter = EnvFilter::from_env("CHALK_DEBUG"); - let layer = HierarchicalLayer::default() - .with_indent_lines(true) - .with_ansi(false) - .with_indent_amount(2) - .with_writer(std::io::stderr); - let subscriber = Registry::default().with(filter).with(layer); - subscriber::set_global_default(subscriber)?; - Ok(()) - } -} - fn run_server() -> Result<()> { - log::info!("server version {} will start", env!("REV")); + tracing::info!("server version {} will start", env!("REV")); let (connection, io_threads) = Connection::stdio(); let (initialize_id, initialize_params) = connection.initialize_start()?; - log::info!("InitializeParams: {}", initialize_params); + tracing::info!("InitializeParams: {}", initialize_params); let initialize_params = from_json::<lsp_types::InitializeParams>("InitializeParams", initialize_params)?; @@ -176,7 +154,7 @@ fn run_server() -> Result<()> { connection.initialize_finish(initialize_id, initialize_result)?; if let Some(client_info) = initialize_params.client_info { - log::info!("Client '{}' {}", client_info.name, client_info.version.unwrap_or_default()); + tracing::info!("Client '{}' {}", client_info.name, client_info.version.unwrap_or_default()); } if config.linked_projects().is_empty() && config.detached_files().is_empty() { @@ -193,9 +171,9 @@ fn run_server() -> Result<()> { .unwrap_or_else(|| vec![config.root_path.clone()]); let discovered = ProjectManifest::discover_all(&workspace_roots); - log::info!("discovered projects: {:?}", discovered); + tracing::info!("discovered projects: {:?}", discovered); if discovered.is_empty() { - log::error!("failed to find any projects in {:?}", workspace_roots); + tracing::error!("failed to find any projects in {:?}", workspace_roots); } config.discovered_projects = Some(discovered); } @@ -203,6 +181,6 @@ fn run_server() -> Result<()> { rust_analyzer::main_loop(config, connection)?; io_threads.join()?; - log::info!("server did shut down"); + tracing::info!("server did shut down"); Ok(()) } diff --git a/crates/rust-analyzer/src/caps.rs b/crates/rust-analyzer/src/caps.rs index 9469776db8..1823fddc08 100644 --- a/crates/rust-analyzer/src/caps.rs +++ b/crates/rust-analyzer/src/caps.rs @@ -131,7 +131,7 @@ fn completions_resolve_provider(client_caps: &ClientCapabilities) -> Option<bool if completion_item_edit_resolve(client_caps) { Some(true) } else { - log::info!("No `additionalTextEdits` completion resolve capability was found in the client capabilities, autoimport completion is disabled"); + tracing::info!("No `additionalTextEdits` completion resolve capability was found in the client capabilities, autoimport completion is disabled"); None } } diff --git a/crates/rust-analyzer/src/cli/load_cargo.rs b/crates/rust-analyzer/src/cli/load_cargo.rs index 65607bbc6f..7b6404eb2a 100644 --- a/crates/rust-analyzer/src/cli/load_cargo.rs +++ b/crates/rust-analyzer/src/cli/load_cargo.rs @@ -85,7 +85,7 @@ pub fn load_workspace( version: 0, }); - log::debug!("crate graph: {:?}", crate_graph); + tracing::debug!("crate graph: {:?}", crate_graph); let host = load_crate_graph(crate_graph, project_folders.source_root_config, &mut vfs, &receiver); diff --git a/crates/rust-analyzer/src/config.rs b/crates/rust-analyzer/src/config.rs index 22da92779e..44a4330284 100644 --- a/crates/rust-analyzer/src/config.rs +++ b/crates/rust-analyzer/src/config.rs @@ -432,7 +432,7 @@ impl Config { } } pub fn update(&mut self, mut json: serde_json::Value) { - log::info!("updating config from JSON: {:#}", json); + tracing::info!("updating config from JSON: {:#}", json); if json.is_null() || json.as_object().map_or(false, |it| it.is_empty()) { return; } @@ -478,7 +478,9 @@ impl Config { ManifestOrProjectJson::Manifest(it) => { let path = self.root_path.join(it); ProjectManifest::from_manifest_file(path) - .map_err(|e| log::error!("failed to load linked project: {}", e)) + .map_err(|e| { + tracing::error!("failed to load linked project: {}", e) + }) .ok()? .into() } diff --git a/crates/rust-analyzer/src/dispatch.rs b/crates/rust-analyzer/src/dispatch.rs index 07ab46647f..9cfd6c35af 100644 --- a/crates/rust-analyzer/src/dispatch.rs +++ b/crates/rust-analyzer/src/dispatch.rs @@ -88,7 +88,7 @@ impl<'a> RequestDispatcher<'a> { pub(crate) fn finish(&mut self) { if let Some(req) = self.req.take() { - log::error!("unknown request: {:?}", req); + tracing::error!("unknown request: {:?}", req); let response = lsp_server::Response::new_err( req.id, lsp_server::ErrorCode::MethodNotFound as i32, @@ -208,7 +208,7 @@ impl<'a> NotificationDispatcher<'a> { pub(crate) fn finish(&mut self) { if let Some(not) = &self.not { if !not.method.starts_with("$/") { - log::error!("unhandled notification: {:?}", not); + tracing::error!("unhandled notification: {:?}", not); } } } diff --git a/crates/rust-analyzer/src/global_state.rs b/crates/rust-analyzer/src/global_state.rs index c2b71327da..f2a40cb199 100644 --- a/crates/rust-analyzer/src/global_state.rs +++ b/crates/rust-analyzer/src/global_state.rs @@ -271,7 +271,7 @@ impl GlobalState { } let duration = start.elapsed(); - log::info!("handled {} - ({}) in {:0.2?}", method, response.id, duration); + tracing::info!("handled {} - ({}) in {:0.2?}", method, response.id, duration); self.send(response.into()); } } diff --git a/crates/rust-analyzer/src/handlers.rs b/crates/rust-analyzer/src/handlers.rs index d196db6f59..aa56a02818 100644 --- a/crates/rust-analyzer/src/handlers.rs +++ b/crates/rust-analyzer/src/handlers.rs @@ -1651,7 +1651,7 @@ fn run_rustfmt( } } Err(_) => { - log::error!( + tracing::error!( "Unable to get file path for {}, rustfmt.toml might be ignored", text_document.uri ); @@ -1721,7 +1721,7 @@ fn run_rustfmt( // formatting because otherwise an error is surfaced to the user on top of the // syntax error diagnostics they're already receiving. This is especially jarring // if they have format on save enabled. - log::info!("rustfmt exited with status 1, assuming parse error and ignoring"); + tracing::info!("rustfmt exited with status 1, assuming parse error and ignoring"); Ok(None) } _ => { diff --git a/crates/rust-analyzer/src/main_loop.rs b/crates/rust-analyzer/src/main_loop.rs index c2aba3ad70..8995d5a9b1 100644 --- a/crates/rust-analyzer/src/main_loop.rs +++ b/crates/rust-analyzer/src/main_loop.rs @@ -27,7 +27,7 @@ use crate::{ }; pub fn main_loop(config: Config, connection: Connection) -> Result<()> { - log::info!("initial config: {:#?}", config); + tracing::info!("initial config: {:#?}", config); // Windows scheduler implements priority boosts: if thread waits for an // event (like a condvar), and event fires, priority of the thread is @@ -182,10 +182,10 @@ impl GlobalState { // NOTE: don't count blocking select! call as a loop-turn time let _p = profile::span("GlobalState::handle_event"); - log::info!("handle_event({:?})", event); + tracing::info!("handle_event({:?})", event); let task_queue_len = self.task_pool.handle.len(); if task_queue_len > 0 { - log::info!("task queue len: {}", task_queue_len); + tracing::info!("task queue len: {}", task_queue_len); } let was_quiescent = self.is_quiescent(); @@ -359,7 +359,7 @@ impl GlobalState { diag.fixes, ), Err(err) => { - log::error!( + tracing::error!( "File with cargo diagnostic not found in VFS: {}", err ); @@ -380,7 +380,7 @@ impl GlobalState { flycheck::Progress::DidCancel => (Progress::End, None), flycheck::Progress::DidFinish(result) => { if let Err(err) = result { - log::error!("cargo check failed: {}", err) + tracing::error!("cargo check failed: {}", err) } (Progress::End, None) } @@ -486,7 +486,7 @@ impl GlobalState { let loop_duration = loop_start.elapsed(); if loop_duration > Duration::from_millis(100) { - log::warn!("overly long loop turn: {:?}", loop_duration); + tracing::warn!("overly long loop turn: {:?}", loop_duration); self.poke_rust_analyzer_developer(format!( "overly long loop turn: {:?}", loop_duration @@ -617,7 +617,7 @@ impl GlobalState { .insert(path.clone(), DocumentData::new(params.text_document.version)) .is_err() { - log::error!("duplicate DidOpenTextDocument: {}", path) + tracing::error!("duplicate DidOpenTextDocument: {}", path) } this.vfs .write() @@ -635,7 +635,7 @@ impl GlobalState { doc.version = params.text_document.version; } None => { - log::error!("expected DidChangeTextDocument: {}", path); + tracing::error!("expected DidChangeTextDocument: {}", path); return Ok(()); } }; @@ -652,7 +652,7 @@ impl GlobalState { .on::<lsp_types::notification::DidCloseTextDocument>(|this, params| { if let Ok(path) = from_proto::vfs_path(¶ms.text_document.uri) { if this.mem_docs.remove(&path).is_err() { - log::error!("orphan DidCloseTextDocument: {}", path); + tracing::error!("orphan DidCloseTextDocument: {}", path); } this.semantic_tokens_cache.lock().remove(¶ms.text_document.uri); @@ -683,12 +683,12 @@ impl GlobalState { }], }, |this, resp| { - log::debug!("config update response: '{:?}", resp); + tracing::debug!("config update response: '{:?}", resp); let lsp_server::Response { error, result, .. } = resp; match (error, result) { (Some(err), _) => { - log::error!("failed to fetch the server settings: {:?}", err) + tracing::error!("failed to fetch the server settings: {:?}", err) } (None, Some(mut configs)) => { if let Some(json) = configs.get_mut(0) { @@ -699,7 +699,7 @@ impl GlobalState { this.update_configuration(config); } } - (None, None) => log::error!( + (None, None) => tracing::error!( "received empty server settings response from the client" ), } @@ -727,7 +727,7 @@ impl GlobalState { .map(|path| self.vfs.read().0.file_id(path).unwrap()) .collect::<Vec<_>>(); - log::trace!("updating notifications for {:?}", subscriptions); + tracing::trace!("updating notifications for {:?}", subscriptions); let snapshot = self.snapshot(); self.task_pool.handle.spawn(move || { @@ -737,7 +737,7 @@ impl GlobalState { handlers::publish_diagnostics(&snapshot, file_id) .map_err(|err| { if !is_cancelled(&*err) { - log::error!("failed to compute diagnostics: {:?}", err); + tracing::error!("failed to compute diagnostics: {:?}", err); } () }) diff --git a/crates/rust-analyzer/src/reload.rs b/crates/rust-analyzer/src/reload.rs index efac6d6868..fa9f05bc38 100644 --- a/crates/rust-analyzer/src/reload.rs +++ b/crates/rust-analyzer/src/reload.rs @@ -61,7 +61,7 @@ impl GlobalState { if !changes.iter().any(|(path, kind)| is_interesting(path, *kind)) { return; } - log::info!( + tracing::info!( "Requesting workspace reload because of the following changes: {}", itertools::join( changes @@ -153,7 +153,7 @@ impl GlobalState { if !self.fetch_workspaces_queue.should_start_op() { return; } - log::info!("will fetch workspaces"); + tracing::info!("will fetch workspaces"); self.task_pool.handle.spawn_with_sender({ let linked_projects = self.config.linked_projects(); @@ -196,7 +196,7 @@ impl GlobalState { .push(project_model::ProjectWorkspace::load_detached_files(detached_files)); } - log::info!("did fetch workspaces {:?}", workspaces); + tracing::info!("did fetch workspaces {:?}", workspaces); sender .send(Task::FetchWorkspace(ProjectWorkspaceProgress::End(workspaces))) .unwrap(); @@ -245,10 +245,10 @@ impl GlobalState { pub(crate) fn switch_workspaces(&mut self) { let _p = profile::span("GlobalState::switch_workspaces"); - log::info!("will switch workspaces"); + tracing::info!("will switch workspaces"); if let Some(error_message) = self.fetch_workspace_error() { - log::error!("failed to switch workspaces: {}", error_message); + tracing::error!("failed to switch workspaces: {}", error_message); if !self.workspaces.is_empty() { // It only makes sense to switch to a partially broken workspace // if we don't have any workspace at all yet. @@ -257,7 +257,7 @@ impl GlobalState { } if let Some(error_message) = self.fetch_build_data_error() { - log::error!("failed to switch build data: {}", error_message); + tracing::error!("failed to switch build data: {}", error_message); } let workspaces = self @@ -367,7 +367,7 @@ impl GlobalState { Some((path, args)) => match ProcMacroClient::extern_process(path.clone(), args) { Ok(it) => Some(it), Err(err) => { - log::error!( + tracing::error!( "Failed to run proc_macro_srv from path {}, error: {:?}", path.display(), err @@ -407,7 +407,7 @@ impl GlobalState { } let res = vfs.file_id(&vfs_path); if res.is_none() { - log::warn!("failed to load {}", path.display()) + tracing::warn!("failed to load {}", path.display()) } res }; @@ -425,7 +425,7 @@ impl GlobalState { self.analysis_host.apply_change(change); self.process_changes(); self.reload_flycheck(); - log::info!("did switch workspaces"); + tracing::info!("did switch workspaces"); } fn fetch_workspace_error(&self) -> Option<String> { diff --git a/crates/rust-analyzer/tests/slow-tests/support.rs b/crates/rust-analyzer/tests/slow-tests/support.rs index 260a504e76..5cf9158082 100644 --- a/crates/rust-analyzer/tests/slow-tests/support.rs +++ b/crates/rust-analyzer/tests/slow-tests/support.rs @@ -71,7 +71,10 @@ impl<'a> Project<'a> { let tmp_dir = self.tmp_dir.unwrap_or_else(TestDir::new); static INIT: Once = Once::new(); INIT.call_once(|| { - env_logger::builder().is_test(true).parse_env("RA_LOG").try_init().unwrap(); + tracing_subscriber::fmt() + .with_test_writer() + .with_env_filter(tracing_subscriber::EnvFilter::from_env("RA_LOG")) + .init(); profile::init_from(crate::PROFILE); }); diff --git a/crates/vfs-notify/Cargo.toml b/crates/vfs-notify/Cargo.toml index a31654d263..ecd589c582 100644 --- a/crates/vfs-notify/Cargo.toml +++ b/crates/vfs-notify/Cargo.toml @@ -9,7 +9,7 @@ edition = "2018" doctest = false [dependencies] -log = "0.4.8" +tracing = "0.1" rustc-hash = "1.0" jod-thread = "0.1.0" walkdir = "2.3.1" diff --git a/crates/vfs-notify/src/lib.rs b/crates/vfs-notify/src/lib.rs index 960d988a4c..637438bd66 100644 --- a/crates/vfs-notify/src/lib.rs +++ b/crates/vfs-notify/src/lib.rs @@ -76,7 +76,7 @@ impl NotifyActor { } fn run(mut self, inbox: Receiver<Message>) { while let Some(event) = self.next_event(&inbox) { - log::debug!("vfs-notify event: {:?}", event); + tracing::debug!("vfs-notify event: {:?}", event); match event { Event::Message(msg) => match msg { Message::Config(config) => { @@ -227,5 +227,5 @@ fn read(path: &AbsPath) -> Option<Vec<u8>> { } fn log_notify_error<T>(res: notify::Result<T>) -> Option<T> { - res.map_err(|err| log::warn!("notify error: {}", err)).ok() + res.map_err(|err| tracing::warn!("notify error: {}", err)).ok() } |