Repository: rust-lang/rust-analyzer
Pull request #18227 (2024-10-01 21:19:44)

internal: add json `tracing` Layer for profiling startup
On `buck2/integrations/rust-project`, this results in the following being printed:

```json
{"name":"discover_command","elapsed_ms":18703}
{"name":"parallel_prime_caches","elapsed_ms":0}
{"name":"vfs_load","elapsed_ms":5895}
{"name":"vfs_load","elapsed_ms":547}
{"name":"parallel_prime_caches","elapsed_ms":23}
{"name":"parallel_prime_caches","elapsed_ms":84}
{"name":"parallel_prime_caches","elapsed_ms":5819}
```

davidbarsky: The following—which is in this PR—works properly and doesn't result in [this event](https://github.com/rust-lang/rust-analyzer/blob/28830ff2f1158ee92f4852ef3ec35af0935d1562/crates/hir-ty/src/chalk_db.rs#L849-L855) being logged:

```rust
impl<T> Config<T>
where
    T: for<'writer> MakeWriter<'writer> + Send + Sync + 'static,
{
    pub fn init(self) -> anyhow::Result<()> {
        let targets_filter: Targets = self
            .filter
            .parse()
            .with_context(|| format!("invalid log filter: `{}`", self.filter))?;

        let writer = self.writer;

        let ra_fmt_layer = tracing_subscriber::fmt::layer()
            .with_target(false)
            .with_ansi(false)
            .with_writer(writer);

        let chalk_layer = match self.chalk_filter {
            Some(chalk_filter) => {
                let level: LevelFilter =
                    chalk_filter.parse().with_context(|| "invalid chalk log filter")?;

                let chalk_filter = Targets::new()
                    .with_target("chalk_solve", level)
                    .with_target("chalk_ir", level)
                    .with_target("chalk_recursive", level);
                HierarchicalLayer::default()
                    .with_indent_lines(true)
                    .with_ansi(false)
                    .with_indent_amount(2)
                    .with_writer(io::stderr)
                    .with_filter(chalk_filter)
                    .boxed()
            }
            None => HierarchicalLayer::default().with_filter(LevelFilter::OFF).boxed(),
        };

        let profiler_layer = match self.profile_filter {
            Some(spec) => hprof::layer(&spec).boxed(),
            None => hprof::layer("").with_filter(LevelFilter::OFF).boxed(),
        };

        let json_profiling_filter = filter_fn(|metadata| {
            let name = metadata.name();
            let matches_name =
                name == "vfs_load" || name == "parallel_prime_caches" || name == "discover_command";

            matches_name && metadata.is_span()
        });

        let subscriber = Registry::default()
            .with(ra_fmt_layer.with_filter(targets_filter))
            .with(hprof::JsonTimingLayer.with_filter(json_profiling_filter))
            .with(profiler_layer)
            .with(chalk_layer);

        tracing::subscriber::set_global_default(subscriber)?;

        Ok(())
    }
}
```

The following, however, *does* result in [this event](https://github.com/rust-lang/rust-analyzer/blob/28830ff2f1158ee92f4852ef3ec35af0935d1562/crates/hir-ty/src/chalk_db.rs#L849-L855) being logged:

```rust
impl<T> Config<T>
where
    T: for<'writer> MakeWriter<'writer> + Send + Sync + 'static,
{
    pub fn init(self) -> anyhow::Result<()> {
        let targets_filter: Targets = self
            .filter
            .parse()
            .with_context(|| format!("invalid log filter: `{}`", self.filter))?;

        let writer = self.writer;

        let ra_fmt_layer = tracing_subscriber::fmt::layer()
            .with_target(false)
            .with_ansi(false)
            .with_writer(writer);

        let mut chalk_layer = None;
        if let Some(chalk_filter) = self.chalk_filter {
            let level: LevelFilter =
                chalk_filter.parse().with_context(|| "invalid chalk log filter")?;

            let chalk_filter = Targets::new()
                .with_target("chalk_solve", level)
                .with_target("chalk_ir", level)
                .with_target("chalk_recursive", level);
            chalk_layer = Some(
                HierarchicalLayer::default()
                    .with_indent_lines(true)
                    .with_ansi(false)
                    .with_indent_amount(2)
                    .with_writer(io::stderr)
                    .with_filter(chalk_filter),
            );
        };

        let mut profiler_layer = None;
        if let Some(spec) = self.profile_filter {
            profiler_layer = Some(hprof::layer(&spec));
        }

        let json_profiling_filter = filter_fn(|metadata| {
            let name = metadata.name();
            let matches_name =
                name == "vfs_load" || name == "parallel_prime_caches" || name == "discover_command";

            matches_name && metadata.is_span()
        });

        let subscriber = Registry::default()
            .with(ra_fmt_layer.with_filter(targets_filter))
            .with(hprof::JsonTimingLayer.with_filter(json_profiling_filter))
            .with(profiler_layer)
            .with(chalk_layer);

        tracing::subscriber::set_global_default(subscriber)?;

        Ok(())
    }
}
```

I'll try and get a minimal reproduction on tracing-subscriber.


Patch:
diff --git a/crates/hir-expand/src/db.rs b/crates/hir-expand/src/db.rs
index 484a8662eb..584f9631e3 100644
--- a/crates/hir-expand/src/db.rs
+++ b/crates/hir-expand/src/db.rs
@@ -16,10 +16,7 @@ use crate::{
     cfg_process,
     declarative::DeclarativeMacroExpander,
     fixup::{self, SyntaxFixupUndoInfo},
-    hygiene::{
-        span_with_call_site_ctxt, span_with_def_site_ctxt, span_with_mixed_site_ctxt,
-        SyntaxContextExt as _,
-    },
+    hygiene::{span_with_call_site_ctxt, span_with_def_site_ctxt, span_with_mixed_site_ctxt},
     proc_macro::ProcMacros,
     span_map::{RealSpanMap, SpanMap, SpanMapRef},
     tt, AstId, BuiltinAttrExpander, BuiltinDeriveExpander, BuiltinFnLikeExpander,
@@ -303,16 +300,14 @@ pub fn expand_speculative(
         token_tree_to_syntax_node(&speculative_expansion.value, expand_to, loc.def.edition);
 
     let syntax_node = node.syntax_node();
-    let (token, _) = rev_tmap
+    let token = rev_tmap
         .ranges_with_span(span_map.span_for_range(token_to_map.text_range()))
-        .filter_map(|(range, ctx)| syntax_node.covering_element(range).into_token().zip(Some(ctx)))
-        .min_by_key(|(t, ctx)| {
-            // prefer tokens of the same kind and text, as well as non opaque marked ones
+        .filter_map(|range| syntax_node.covering_element(range).into_token())
+        .min_by_key(|t| {
+            // prefer tokens of the same kind and text
             // Note the inversion of the score here, as we want to prefer the first token in case
             // of all tokens having the same score
-            ctx.is_opaque(db) as u8
-                + 2 * (t.kind() != token_to_map.kind()) as u8
-                + 4 * ((t.text() != token_to_map.text()) as u8)
+            (t.kind() != token_to_map.kind()) as u8 + 2 * ((t.text() != token_to_map.text()) as u8)
         })?;
     Some((node.syntax_node(), token))
 }
diff --git a/crates/hir-expand/src/hygiene.rs b/crates/hir-expand/src/hygiene.rs
index 5e1448f795..cc02332207 100644
--- a/crates/hir-expand/src/hygiene.rs
+++ b/crates/hir-expand/src/hygiene.rs
@@ -151,7 +151,6 @@ pub trait SyntaxContextExt {
     fn remove_mark(&mut self, db: &dyn ExpandDatabase) -> (Option<MacroCallId>, Transparency);
     fn outer_mark(self, db: &dyn ExpandDatabase) -> (Option<MacroCallId>, Transparency);
     fn marks(self, db: &dyn ExpandDatabase) -> Vec<(MacroCallId, Transparency)>;
-    fn is_opaque(self, db: &dyn ExpandDatabase) -> bool;
 }
 
 impl SyntaxContextExt for SyntaxContextId {
@@ -178,9 +177,6 @@ impl SyntaxContextExt for SyntaxContextId {
         marks.reverse();
         marks
     }
-    fn is_opaque(self, db: &dyn ExpandDatabase) -> bool {
-        !self.is_root() && db.lookup_intern_syntax_context(self).outer_transparency.is_opaque()
-    }
 }
 
 // FIXME: Make this a SyntaxContextExt method once we have RPIT
diff --git a/crates/hir-expand/src/lib.rs b/crates/hir-expand/src/lib.rs
index 56cb5fd375..9538097949 100644
--- a/crates/hir-expand/src/lib.rs
+++ b/crates/hir-expand/src/lib.rs
@@ -25,7 +25,6 @@ mod prettify_macro_expansion_;
 
 use attrs::collect_attrs;
 use rustc_hash::FxHashMap;
-use stdx::TupleExt;
 use triomphe::Arc;
 
 use std::hash::Hash;
@@ -773,15 +772,14 @@ impl ExpansionInfo {
     /// Maps the passed in file range down into a macro expansion if it is the input to a macro call.
     ///
     /// Note this does a linear search through the entire backing vector of the spanmap.
-    // FIXME: Consider adding a reverse map to ExpansionInfo to get rid of the linear search which
-    // potentially results in quadratic look ups (notably this might improve semantic highlighting perf)
     pub fn map_range_down_exact(
         &self,
         span: Span,
-    ) -> Option<InMacroFile<impl Iterator<Item = (SyntaxToken, SyntaxContextId)> + '_>> {
-        let tokens = self.exp_map.ranges_with_span_exact(span).flat_map(move |(range, ctx)| {
-            self.expanded.value.covering_element(range).into_token().zip(Some(ctx))
-        });
+    ) -> Option<InMacroFile<impl Iterator<Item = SyntaxToken> + '_>> {
+        let tokens = self
+            .exp_map
+            .ranges_with_span_exact(span)
+            .flat_map(move |range| self.expanded.value.covering_element(range).into_token());
 
         Some(InMacroFile::new(self.expanded.file_id, tokens))
     }
@@ -793,10 +791,11 @@ impl ExpansionInfo {
     pub fn map_range_down(
         &self,
         span: Span,
-    ) -> Option<InMacroFile<impl Iterator<Item = (SyntaxToken, SyntaxContextId)> + '_>> {
-        let tokens = self.exp_map.ranges_with_span(span).flat_map(move |(range, ctx)| {
-            self.expanded.value.covering_element(range).into_token().zip(Some(ctx))
-        });
+    ) -> Option<InMacroFile<impl Iterator<Item = SyntaxToken> + '_>> {
+        let tokens = self
+            .exp_map
+            .ranges_with_span(span)
+            .flat_map(move |range| self.expanded.value.covering_element(range).into_token());
 
         Some(InMacroFile::new(self.expanded.file_id, tokens))
     }
@@ -846,8 +845,7 @@ impl ExpansionInfo {
                     self.arg.file_id,
                     arg_map
                         .ranges_with_span_exact(span)
-                        .filter(|(range, _)| range.intersect(arg_range).is_some())
-                        .map(TupleExt::head)
+                        .filter(|range| range.intersect(arg_range).is_some())
                         .collect(),
                 )
             }
diff --git a/crates/hir/src/lib.rs b/crates/hir/src/lib.rs
index 32b14c383a..30e023e1a4 100644
--- a/crates/hir/src/lib.rs
+++ b/crates/hir/src/lib.rs
@@ -556,7 +556,7 @@ impl Module {
         acc: &mut Vec<AnyDiagnostic>,
         style_lints: bool,
     ) {
-        let _p = tracing::info_span!("Module::diagnostics", name = ?self.name(db)).entered();
+        let _p = tracing::info_span!("diagnostics", name = ?self.name(db)).entered();
         let edition = db.crate_graph()[self.id.krate()].edition;
         let def_map = self.id.def_map(db.upcast());
         for diag in def_map.diagnostics() {
diff --git a/crates/hir/src/semantics.rs b/crates/hir/src/semantics.rs
index b27f1fbb5d..fa18182fbb 100644
--- a/crates/hir/src/semantics.rs
+++ b/crates/hir/src/semantics.rs
@@ -24,7 +24,6 @@ use hir_expand::{
     builtin::{BuiltinFnLikeExpander, EagerExpander},
     db::ExpandDatabase,
     files::InRealFile,
-    hygiene::SyntaxContextExt as _,
     inert_attr_macro::find_builtin_attr_idx,
     name::AsName,
     FileRange, InMacroFile, MacroCallId, MacroFileId, MacroFileIdExt,
@@ -33,7 +32,7 @@ use intern::Symbol;
 use itertools::Itertools;
 use rustc_hash::{FxHashMap, FxHashSet};
 use smallvec::{smallvec, SmallVec};
-use span::{EditionedFileId, FileId, HirFileIdRepr, SyntaxContextId};
+use span::{EditionedFileId, FileId, HirFileIdRepr};
 use stdx::TupleExt;
 use syntax::{
     algo::skip_trivia_token,
@@ -609,7 +608,7 @@ impl<'db> SemanticsImpl<'db> {
         let quote = string.open_quote_text_range()?;
 
         let token = self.wrap_token_infile(string.syntax().clone()).into_real_file().ok()?;
-        self.descend_into_macros_breakable(token, |token, _| {
+        self.descend_into_macros_breakable(token, |token| {
             (|| {
                 let token = token.value;
                 let string = ast::String::cast(token)?;
@@ -656,7 +655,7 @@ impl<'db> SemanticsImpl<'db> {
         let original_string = ast::String::cast(original_token.clone())?;
         let original_token = self.wrap_token_infile(original_token).into_real_file().ok()?;
         let quote = original_string.open_quote_text_range()?;
-        self.descend_into_macros_breakable(original_token, |token, _| {
+        self.descend_into_macros_breakable(original_token, |token| {
             (|| {
                 let token = token.value;
                 self.resolve_offset_in_format_args(
@@ -719,7 +718,7 @@ impl<'db> SemanticsImpl<'db> {
             // node is just the token, so descend the token
             self.descend_into_macros_impl(
                 InRealFile::new(file_id, first),
-                &mut |InFile { value, .. }, _ctx| {
+                &mut |InFile { value, .. }| {
                     if let Some(node) = value
                         .parent_ancestors()
                         .take_while(|it| it.text_range() == value.text_range())
@@ -733,7 +732,7 @@ impl<'db> SemanticsImpl<'db> {
         } else {
             // Descend first and last token, then zip them to look for the node they belong to
             let mut scratch: SmallVec<[_; 1]> = smallvec![];
-            self.descend_into_macros_impl(InRealFile::new(file_id, first), &mut |token, _ctx| {
+            self.descend_into_macros_impl(InRealFile::new(file_id, first), &mut |token| {
                 scratch.push(token);
                 CONTINUE_NO_BREAKS
             });
@@ -741,7 +740,7 @@ impl<'db> SemanticsImpl<'db> {
             let mut scratch = scratch.into_iter();
             self.descend_into_macros_impl(
                 InRealFile::new(file_id, last),
-                &mut |InFile { value: last, file_id: last_fid }, _ctx| {
+                &mut |InFile { value: last, file_id: last_fid }| {
                     if let Some(InFile { value: first, file_id: first_fid }) = scratch.next() {
                         if first_fid == last_fid {
                             if let Some(p) = first.parent() {
@@ -764,9 +763,7 @@ impl<'db> SemanticsImpl<'db> {
         res
     }
 
-    // FIXME: This isn't quite right wrt to inner attributes
-    /// Does a syntactic traversal to check whether this token might be inside a macro call
-    pub fn might_be_inside_macro_call(&self, token: &SyntaxToken) -> bool {
+    fn is_inside_macro_call(token: &SyntaxToken) -> bool {
         token.parent_ancestors().any(|ancestor| {
             if ast::MacroCall::can_cast(ancestor.kind()) {
                 return true;
@@ -784,14 +781,25 @@ impl<'db> SemanticsImpl<'db> {
         })
     }
 
+    pub fn descend_into_macros_exact_if_in_macro(
+        &self,
+        token: SyntaxToken,
+    ) -> SmallVec<[SyntaxToken; 1]> {
+        if Self::is_inside_macro_call(&token) {
+            self.descend_into_macros_exact(token)
+        } else {
+            smallvec![token]
+        }
+    }
+
     pub fn descend_into_macros_cb(
         &self,
         token: SyntaxToken,
-        mut cb: impl FnMut(InFile<SyntaxToken>, SyntaxContextId),
+        mut cb: impl FnMut(InFile<SyntaxToken>),
     ) {
         if let Ok(token) = self.wrap_token_infile(token).into_real_file() {
-            self.descend_into_macros_impl(token, &mut |t, ctx| {
-                cb(t, ctx);
+            self.descend_into_macros_impl(token, &mut |t| {
+                cb(t);
                 CONTINUE_NO_BREAKS
             });
         }
@@ -800,7 +808,7 @@ impl<'db> SemanticsImpl<'db> {
     pub fn descend_into_macros(&self, token: SyntaxToken) -> SmallVec<[SyntaxToken; 1]> {
         let mut res = smallvec![];
         if let Ok(token) = self.wrap_token_infile(token.clone()).into_real_file() {
-            self.descend_into_macros_impl(token, &mut |t, _ctx| {
+            self.descend_into_macros_impl(token, &mut |t| {
                 res.push(t.value);
                 CONTINUE_NO_BREAKS
             });
@@ -811,27 +819,10 @@ impl<'db> SemanticsImpl<'db> {
         res
     }
 
-    pub fn descend_into_macros_no_opaque(&self, token: SyntaxToken) -> SmallVec<[SyntaxToken; 1]> {
-        let mut res = smallvec![];
-        if let Ok(token) = self.wrap_token_infile(token.clone()).into_real_file() {
-            self.descend_into_macros_impl(token, &mut |t, ctx| {
-                if !ctx.is_opaque(self.db.upcast()) {
-                    // Don't descend into opaque contexts
-                    res.push(t.value);
-                }
-                CONTINUE_NO_BREAKS
-            });
-        }
-        if res.is_empty() {
-            res.push(token);
-        }
-        res
-    }
-
     pub fn descend_into_macros_breakable<T>(
         &self,
         token: InRealFile<SyntaxToken>,
-        mut cb: impl FnMut(InFile<SyntaxToken>, SyntaxContextId) -> ControlFlow<T>,
+        mut cb: impl FnMut(InFile<SyntaxToken>) -> ControlFlow<T>,
     ) -> Option<T> {
         self.descend_into_macros_impl(token.clone(), &mut cb)
     }
@@ -843,12 +834,10 @@ impl<'db> SemanticsImpl<'db> {
         let text = token.text();
         let kind = token.kind();
 
-        self.descend_into_macros_cb(token.clone(), |InFile { value, file_id: _ }, ctx| {
+        self.descend_into_macros_cb(token.clone(), |InFile { value, file_id: _ }| {
             let mapped_kind = value.kind();
             let any_ident_match = || kind.is_any_identifier() && value.kind().is_any_identifier();
-            let matches = (kind == mapped_kind || any_ident_match())
-                && text == value.text()
-                && !ctx.is_opaque(self.db.upcast());
+            let matches = (kind == mapped_kind || any_ident_match()) && text == value.text();
             if matches {
                 r.push(value);
             }
@@ -865,21 +854,17 @@ impl<'db> SemanticsImpl<'db> {
         let text = token.text();
         let kind = token.kind();
         if let Ok(token) = self.wrap_token_infile(token.clone()).into_real_file() {
-            self.descend_into_macros_breakable(
-                token.clone(),
-                |InFile { value, file_id: _ }, _ctx| {
-                    let mapped_kind = value.kind();
-                    let any_ident_match =
-                        || kind.is_any_identifier() && value.kind().is_any_identifier();
-                    let matches =
-                        (kind == mapped_kind || any_ident_match()) && text == value.text();
-                    if matches {
-                        ControlFlow::Break(value)
-                    } else {
-                        ControlFlow::Continue(())
-                    }
-                },
-            )
+            self.descend_into_macros_breakable(token.clone(), |InFile { value, file_id: _ }| {
+                let mapped_kind = value.kind();
+                let any_ident_match =
+                    || kind.is_any_identifier() && value.kind().is_any_identifier();
+                let matches = (kind == mapped_kind || any_ident_match()) && text == value.text();
+                if matches {
+                    ControlFlow::Break(value)
+                } else {
+                    ControlFlow::Continue(())
+                }
+            })
         } else {
             None
         }
@@ -889,7 +874,7 @@ impl<'db> SemanticsImpl<'db> {
     fn descend_into_macros_impl<T>(
         &self,
         InRealFile { value: token, file_id }: InRealFile<SyntaxToken>,
-        f: &mut dyn FnMut(InFile<SyntaxToken>, SyntaxContextId) -> ControlFlow<T>,
+        f: &mut dyn FnMut(InFile<SyntaxToken>) -> ControlFlow<T>,
     ) -> Option<T> {
         let _p = tracing::info_span!("descend_into_macros_impl").entered();
         let (sa, span, file_id) = token
@@ -913,8 +898,7 @@ impl<'db> SemanticsImpl<'db> {
         // These are tracked to know which macro calls we still have to look into
         // the tokens themselves aren't that interesting as the span that is being used to map
         // things down never changes.
-        let mut stack: Vec<(_, SmallVec<[_; 2]>)> =
-            vec![(file_id, smallvec![(token, SyntaxContextId::ROOT)])];
+        let mut stack: Vec<(_, SmallVec<[_; 2]>)> = vec![(file_id, smallvec![token])];
 
         // Process the expansion of a call, pushing all tokens with our span in the expansion back onto our stack
         let process_expansion_for_token = |stack: &mut Vec<_>, macro_file| {
@@ -937,11 +921,11 @@ impl<'db> SemanticsImpl<'db> {
         // Filters out all tokens that contain the given range (usually the macro call), any such
         // token is redundant as the corresponding macro call has already been processed
         let filter_duplicates = |tokens: &mut SmallVec<_>, range: TextRange| {
-            tokens.retain(|(t, _): &mut (SyntaxToken, _)| !range.contains_range(t.text_range()))
+            tokens.retain(|t: &mut SyntaxToken| !range.contains_range(t.text_range()))
         };
 
         while let Some((expansion, ref mut tokens)) = stack.pop() {
-            while let Some((token, ctx)) = tokens.pop() {
+            while let Some(token) = tokens.pop() {
                 let was_not_remapped = (|| {
                     // First expand into attribute invocations
                     let containing_attribute_macro_call = self.with_ctx(|ctx| {
@@ -1052,7 +1036,7 @@ impl<'db> SemanticsImpl<'db> {
                                             let text_range = attr.syntax().text_range();
                                             // remove any other token in this macro input, all their mappings are the
                                             // same as this
-                                            tokens.retain(|(t, _)| {
+                                            tokens.retain(|t| {
                                                 !text_range.contains_range(t.text_range())
                                             });
                                             return process_expansion_for_token(
@@ -1109,7 +1093,7 @@ impl<'db> SemanticsImpl<'db> {
                 .is_none();
 
                 if was_not_remapped {
-                    if let ControlFlow::Break(b) = f(InFile::new(expansion, token), ctx) {
+                    if let ControlFlow::Break(b) = f(InFile::new(expansion, token)) {
                         return Some(b);
                     }
                 }
diff --git a/crates/ide-db/src/search.rs b/crates/ide-db/src/search.rs
index 852ee595be..4166b08339 100644
--- a/crates/ide-db/src/search.rs
+++ b/crates/ide-db/src/search.rs
@@ -529,13 +529,9 @@ impl<'a> FindUsages<'a> {
             })
             .into_iter()
             .flat_map(move |token| {
-                if sema.might_be_inside_macro_call(&token) {
-                    sema.descend_into_macros_exact(token)
-                } else {
-                    <_>::from([token])
-                }
-                .into_iter()
-                .filter_map(|it| it.parent())
+                sema.descend_into_macros_exact_if_in_macro(token)
+                    .into_iter()
+                    .filter_map(|it| it.parent())
             })
     }
 
diff --git a/crates/ide/src/goto_declaration.rs b/crates/ide/src/goto_declaration.rs
index 9dacbd8bad..6ae9dde84b 100644
--- a/crates/ide/src/goto_declaration.rs
+++ b/crates/ide/src/goto_declaration.rs
@@ -29,7 +29,7 @@ pub(crate) fn goto_declaration(
         .find(|it| matches!(it.kind(), IDENT | T![self] | T![super] | T![crate] | T![Self]))?;
     let range = original_token.text_range();
     let info: Vec<NavigationTarget> = sema
-        .descend_into_macros_no_opaque(original_token)
+        .descend_into_macros(original_token)
         .iter()
         .filter_map(|token| {
             let parent = token.parent()?;
diff --git a/crates/ide/src/goto_definition.rs b/crates/ide/src/goto_definition.rs
index c61b2ba84f..f8a07200bc 100644
--- a/crates/ide/src/goto_definition.rs
+++ b/crates/ide/src/goto_definition.rs
@@ -83,7 +83,7 @@ pub(crate) fn goto_definition(
     }
 
     let navs = sema
-        .descend_into_macros_no_opaque(original_token.clone())
+        .descend_into_macros(original_token.clone())
         .into_iter()
         .filter_map(|token| {
             let parent = token.parent()?;
diff --git a/crates/ide/src/goto_type_definition.rs b/crates/ide/src/goto_type_definition.rs
index c7ebd9a353..ca04b7bb5a 100644
--- a/crates/ide/src/goto_type_definition.rs
+++ b/crates/ide/src/goto_type_definition.rs
@@ -69,7 +69,7 @@ pub(crate) fn goto_type_definition(
     }
 
     let range = token.text_range();
-    sema.descend_into_macros_no_opaque(token)
+    sema.descend_into_macros(token)
         .into_iter()
         .filter_map(|token| {
             let ty = sema
diff --git a/crates/ide/src/syntax_highlighting.rs b/crates/ide/src/syntax_highlighting.rs
index 961b2a4c93..927fdaa178 100644
--- a/crates/ide/src/syntax_highlighting.rs
+++ b/crates/ide/src/syntax_highlighting.rs
@@ -409,8 +409,7 @@ fn traverse(
                     let mut r = 0;
                     sema.descend_into_macros_breakable(
                         InRealFile::new(file_id, token.clone()),
-                        |tok, _ctx| {
-                            // FIXME: Consider checking ctx transparency for being opaque?
+                        |tok| {
                             let tok = tok.value;
                             let tok_kind = tok.kind();
 
diff --git a/crates/rust-analyzer/src/bin/main.rs b/crates/rust-analyzer/src/bin/main.rs
index 41b42573f0..ecc8333503 100644
--- a/crates/rust-analyzer/src/bin/main.rs
+++ b/crates/rust-analyzer/src/bin/main.rs
@@ -137,6 +137,7 @@ fn setup_logging(log_file_flag: Option<PathBuf>) -> anyhow::Result<()> {
         filter: env::var("RA_LOG").ok().unwrap_or_else(|| "error".to_owned()),
         chalk_filter: env::var("CHALK_DEBUG").ok(),
         profile_filter: env::var("RA_PROFILE").ok(),
+        json_profile_filter: std::env::var("RA_PROFILE_JSON").ok(),
     }
     .init()?;
 
diff --git a/crates/rust-analyzer/src/lib.rs b/crates/rust-analyzer/src/lib.rs
index 714991e811..234204695c 100644
--- a/crates/rust-analyzer/src/lib.rs
+++ b/crates/rust-analyzer/src/lib.rs
@@ -34,6 +34,7 @@ mod handlers {
 
 pub mod tracing {
     pub mod config;
+    pub mod json;
     pub use config::Config;
     pub mod hprof;
 }
diff --git a/crates/rust-analyzer/src/tracing/config.rs b/crates/rust-analyzer/src/tracing/config.rs
index 1fe2fdc08f..b73f6e7751 100644
--- a/crates/rust-analyzer/src/tracing/config.rs
+++ b/crates/rust-analyzer/src/tracing/config.rs
@@ -1,17 +1,20 @@
 //! 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::io;
+use std::io::{self};
 
 use anyhow::Context;
 use tracing::level_filters::LevelFilter;
 use tracing_subscriber::{
-    filter::Targets, fmt::MakeWriter, layer::SubscriberExt, util::SubscriberInitExt, Layer,
-    Registry,
+    filter::{filter_fn, Targets},
+    fmt::MakeWriter,
+    layer::SubscriberExt,
+    Layer, Registry,
 };
 use tracing_tree::HierarchicalLayer;
 
 use crate::tracing::hprof;
+use crate::tracing::json;
 
 #[derive(Debug)]
 pub struct Config<T> {
@@ -34,6 +37,12 @@ pub struct Config<T> {
     /// env RA_PROFILE=*@3>10        // dump everything, up to depth 3, if it takes more than 10
     /// ```
     pub profile_filter: Option<String>,
+
+    /// Filtering syntax, set in a shell:
+    /// ```
+    /// env RA_PROFILE_JSON=foo|bar|baz
+    /// ```
+    pub json_profile_filter: Option<String>,
 }
 
 impl<T> Config<T>
@@ -41,7 +50,7 @@ where
     T: for<'writer> MakeWriter<'writer> + Send + Sync + 'static,
 {
     pub fn init(self) -> anyhow::Result<()> {
-        let filter: Targets = self
+        let targets_filter: Targets = self
             .filter
             .parse()
             .with_context(|| format!("invalid log filter: `{}`", self.filter))?;
@@ -52,30 +61,58 @@ where
             .with_target(false)
             .with_ansi(false)
             .with_writer(writer)
-            .with_filter(filter);
-
-        let mut chalk_layer = None;
-        if let Some(chalk_filter) = self.chalk_filter {
-            let level: LevelFilter =
-                chalk_filter.parse().with_context(|| "invalid chalk log filter")?;
-
-            let chalk_filter = Targets::new()
-                .with_target("chalk_solve", level)
-                .with_target("chalk_ir", level)
-                .with_target("chalk_recursive", level);
-            chalk_layer = Some(
+            .with_filter(targets_filter);
+
+        let chalk_layer = match self.chalk_filter {
+            Some(chalk_filter) => {
+                let level: LevelFilter =
+                    chalk_filter.parse().with_context(|| "invalid chalk log filter")?;
+
+                let chalk_filter = Targets::new()
+                    .with_target("chalk_solve", level)
+                    .with_target("chalk_ir", level)
+                    .with_target("chalk_recursive", level);
+                // TODO: remove `.with_filter(LevelFilter::OFF)` on the `None` branch.
                 HierarchicalLayer::default()
                     .with_indent_lines(true)
                     .with_ansi(false)
                     .with_indent_amount(2)
                     .with_writer(io::stderr)
-                    .with_filter(chalk_filter),
-            );
+                    .with_filter(chalk_filter)
+                    .boxed()
+            }
+            None => None::<HierarchicalLayer>.with_filter(LevelFilter::OFF).boxed(),
+        };
+
+        // TODO: remove `.with_filter(LevelFilter::OFF)` on the `None` branch.
+        let profiler_layer = match self.profile_filter {
+            Some(spec) => Some(hprof::SpanTree::new(&spec)).with_filter(LevelFilter::INFO),
+            None => None.with_filter(LevelFilter::OFF),
+        };
+
+        let json_profiler_layer = match self.json_profile_filter {
+            Some(spec) => {
+                let filter = json::JsonFilter::from_spec(&spec);
+                let filter = filter_fn(move |metadata| {
+                    let allowed = match &filter.allowed_names {
+                        Some(names) => names.contains(metadata.name()),
+                        None => true,
+                    };
+
+                    allowed && metadata.is_span()
+                });
+                Some(json::TimingLayer::new(std::io::stderr).with_filter(filter))
+            }
+            None => None,
         };
 
-        let profiler_layer = self.profile_filter.map(|spec| hprof::layer(&spec));
+        let subscriber = Registry::default()
+            .with(ra_fmt_layer)
+            .with(json_profiler_layer)
+            .with(profiler_layer)
+            .with(chalk_layer);
 
-        Registry::default().with(ra_fmt_layer).with(chalk_layer).with(profiler_layer).try_init()?;
+        tracing::subscriber::set_global_default(subscriber)?;
 
         Ok(())
     }
diff --git a/crates/rust-analyzer/src/tracing/hprof.rs b/crates/rust-analyzer/src/tracing/hprof.rs
index 2d1604e70b..cad92962f3 100644
--- a/crates/rust-analyzer/src/tracing/hprof.rs
+++ b/crates/rust-analyzer/src/tracing/hprof.rs
@@ -33,6 +33,7 @@
 
 use std::{
     fmt::Write,
+    marker::PhantomData,
     mem,
     time::{Duration, Instant},
 };
@@ -50,53 +51,42 @@ use tracing_subscriber::{
     Layer, Registry,
 };
 
-use crate::tracing::hprof;
-
 pub fn init(spec: &str) -> tracing::subscriber::DefaultGuard {
-    let subscriber = Registry::default().with(layer(spec));
+    let subscriber = Registry::default().with(SpanTree::new(spec));
     tracing::subscriber::set_default(subscriber)
 }
 
-pub fn layer<S>(spec: &str) -> impl Layer<S>
-where
-    S: Subscriber + for<'span> tracing_subscriber::registry::LookupSpan<'span>,
-{
-    let (write_filter, allowed_names) = WriteFilter::from_spec(spec);
-
-    // this filter the first pass for `tracing`: these are all the "profiling" spans, but things like
-    // span depth or duration are not filtered here: that only occurs at write time.
-    let profile_filter = filter::filter_fn(move |metadata| {
-        let allowed = match &allowed_names {
-            Some(names) => names.contains(metadata.name()),
-            None => true,
-        };
-
-        allowed
-            && metadata.is_span()
-            && metadata.level() >= &Level::INFO
-            && !metadata.target().starts_with("salsa")
-            && metadata.name() != "compute_exhaustiveness_and_usefulness"
-            && !metadata.target().starts_with("chalk")
-    });
-
-    hprof::SpanTree::default().aggregate(true).spec_filter(write_filter).with_filter(profile_filter)
-}
-
-#[derive(Default, Debug)]
-pub(crate) struct SpanTree {
+#[derive(Debug)]
+pub(crate) struct SpanTree<S> {
     aggregate: bool,
     write_filter: WriteFilter,
+    _inner: PhantomData<fn(S)>,
 }
 
-impl SpanTree {
-    /// Merge identical sibling spans together.
-    pub(crate) fn aggregate(self, yes: bool) -> SpanTree {
-        SpanTree { aggregate: yes, ..self }
-    }
-
-    /// Add a write-time filter for span duration or tree depth.
-    pub(crate) fn spec_filter(self, write_filter: WriteFilter) -> SpanTree {
-        SpanTree { write_filter, ..self }
+impl<S> SpanTree<S>
+where
+    S: Subscriber + for<'span> tracing_subscriber::registry::LookupSpan<'span>,
+{
+    pub(crate) fn new(spec: &str) -> impl Layer<S> {
+        let (write_filter, allowed_names) = WriteFilter::from_spec(spec);
+
+        // this filter the first pass for `tracing`: these are all the "profiling" spans, but things like
+        // span depth or duration are not filtered here: that only occurs at write time.
+        let profile_filter = filter::filter_fn(move |metadata| {
+            let allowed = match &allowed_names {
+                Some(names) => names.contains(metadata.name()),
+                None => true,
+            };
+
+            allowed
+                && metadata.is_span()
+                && metadata.level() >= &Level::INFO
+                && !metadata.target().starts_with("salsa")
+                && metadata.name() != "compute_exhaustiveness_and_usefulness"
+                && !metadata.target().starts_with("chalk")
+        });
+
+        Self { aggregate: true, write_filter, _inner: PhantomData }.with_filter(profile_filter)
     }
 }
 
@@ -136,7 +126,7 @@ impl<'a> Visit for DataVisitor<'a> {
     }
 }
 
-impl<S> Layer<S> for SpanTree
+impl<S> Layer<S> for SpanTree<S>
 where
     S: Subscriber + for<'span> LookupSpan<'span>,
 {
diff --git a/crates/rust-analyzer/src/tracing/json.rs b/crates/rust-analyzer/src/tracing/json.rs
new file mode 100644
index 0000000000..f540a33b45
--- /dev/null
+++ b/crates/rust-analyzer/src/tracing/json.rs
@@ -0,0 +1,90 @@
+//! A [tracing_subscriber::layer::Layer] that exports new-line delinated JSON.
+//!
+//! Usage:
+//!
+//! ```rust
+//! let layer = json::TimingLayer::new(std::io::stderr);
+//! Registry::default().with(layer).init();
+//! ```
+
+use std::{io::Write as _, marker::PhantomData, time::Instant};
+
+use ide_db::FxHashSet;
+use tracing::{
+    span::{Attributes, Id},
+    Event, Subscriber,
+};
+use tracing_subscriber::{fmt::MakeWriter, layer::Context, registry::LookupSpan, Layer};
+
+struct JsonData {
+    name: &'static str,
+    start: std::time::Instant,
+}
+
+impl JsonData {
+    fn new(name: &'static str) -> Self {
+        Self { name, start: Instant::now() }
+    }
+}
+
+#[derive(Debug)]
+pub(crate) struct TimingLayer<S, W> {
+    writer: W,
+    _inner: PhantomData<fn(S)>,
+}
+
+impl<S, W> TimingLayer<S, W> {
+    pub(crate) fn new(writer: W) -> Self {
+        Self { writer, _inner: PhantomData }
+    }
+}
+
+impl<S, W> Layer<S> for TimingLayer<S, W>
+where
+    S: Subscriber + for<'span> LookupSpan<'span>,
+    W: for<'writer> MakeWriter<'writer> + Send + Sync + 'static,
+{
+    fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) {
+        let span = ctx.span(id).unwrap();
+
+        let data = JsonData::new(attrs.metadata().name());
+        span.extensions_mut().insert(data);
+    }
+
+    fn on_event(&self, _event: &Event<'_>, _ctx: Context<'_, S>) {}
+
+    fn on_close(&self, id: Id, ctx: Context<'_, S>) {
+        #[derive(serde::Serialize)]
+        struct JsonDataInner {
+            name: &'static str,
+            elapsed_ms: u128,
+        }
+
+        let span = ctx.span(&id).unwrap();
+        let Some(data) = span.extensions_mut().remove::<JsonData>() else {
+            return;
+        };
+
+        let data = JsonDataInner { name: data.name, elapsed_ms: data.start.elapsed().as_millis() };
+        let mut out = serde_json::to_string(&data).expect("Unable to serialize data");
+        out.push('\n');
+        self.writer.make_writer().write_all(out.as_bytes()).expect("Unable to write data");
+    }
+}
+
+#[derive(Default, Clone, Debug)]
+pub(crate) struct JsonFilter {
+    pub(crate) allowed_names: Option<FxHashSet<String>>,
+}
+
+impl JsonFilter {
+    pub(crate) fn from_spec(spec: &str) -> Self {
+        let allowed_names = if spec == "*" {
+            None
+        } else {
+            Some(FxHashSet::from_iter(spec.split('|').map(String::from)))
+        };
+
+        Self { allowed_names }
+    }
+}
diff --git a/crates/span/src/hygiene.rs b/crates/span/src/hygiene.rs
index 3863b3e809..cb9c092f5f 100644
--- a/crates/span/src/hygiene.rs
+++ b/crates/span/src/hygiene.rs
@@ -142,12 +142,3 @@ pub enum Transparency {
     /// Def-site spans in procedural macros, identifiers from `macro` by default use this.
     Opaque,
 }
-
-impl Transparency {
-    /// Returns `true` if the transparency is [`Opaque`].
-    ///
-    /// [`Opaque`]: Transparency::Opaque
-    pub fn is_opaque(&self) -> bool {
-        matches!(self, Self::Opaque)
-    }
-}
diff --git a/crates/span/src/map.rs b/crates/span/src/map.rs
index 66bbce1859..f80de05ec6 100644
--- a/crates/span/src/map.rs
+++ b/crates/span/src/map.rs
@@ -55,10 +55,7 @@ where
     /// Returns all [`TextRange`]s that correspond to the given span.
     ///
     /// Note this does a linear search through the entire backing vector.
-    pub fn ranges_with_span_exact(
-        &self,
-        span: SpanData<S>,
-    ) -> impl Iterator<Item = (TextRange, S)> + '_
+    pub fn ranges_with_span_exact(&self, span: SpanData<S>) -> impl Iterator<Item = TextRange> + '_
     where
         S: Copy,
     {
@@ -67,14 +64,14 @@ where
                 return None;
             }
             let start = idx.checked_sub(1).map_or(TextSize::new(0), |prev| self.spans[prev].0);
-            Some((TextRange::new(start, end), s.ctx))
+            Some(TextRange::new(start, end))
         })
     }
 
     /// Returns all [`TextRange`]s whose spans contain the given span.
     ///
     /// Note this does a linear search through the entire backing vector.
-    pub fn ranges_with_span(&self, span: SpanData<S>) -> impl Iterator<Item = (TextRange, S)> + '_
+    pub fn ranges_with_span(&self, span: SpanData<S>) -> impl Iterator<Item = TextRange> + '_
     where
         S: Copy,
     {
@@ -86,7 +83,7 @@ where
                 return None;
             }
             let start = idx.checked_sub(1).map_or(TextSize::new(0), |prev| self.spans[prev].0);
-            Some((TextRange::new(start, end), s.ctx))
+            Some(TextRange::new(start, end))
         })
     }
 
diff --git a/docs/dev/README.md b/docs/dev/README.md
index 002b8ba2a6..12e6d829a0 100644
--- a/docs/dev/README.md
+++ b/docs/dev/README.md
@@ -178,7 +178,15 @@ RA_PROFILE=foo|bar|baz   // enabled only selected entries
 RA_PROFILE=*@3>10        // dump everything, up to depth 3, if it takes more than 10 ms
 ```
 
-In particular, I have `export RA_PROFILE='*>10'` in my shell profile.
+Some rust-analyzer contributors have `export RA_PROFILE='*>10'` in my shell profile.
+
+For machine-readable JSON output, we have the `RA_PROFILE_JSON` env variable. We support
+filtering only by span name:
+
+```
+RA_PROFILE=* // dump everything
+RA_PROFILE_JSON="vfs_load|parallel_prime_caches|discover_command" // dump selected spans
+```
 
 We also have a "counting" profiler which counts number of instances of popular structs.
 It is enabled by `RA_COUNT=1`.


Test patch:
diff --git a/crates/rust-analyzer/tests/slow-tests/support.rs b/crates/rust-analyzer/tests/slow-tests/support.rs
index 06ce984681..18aface632 100644
--- a/crates/rust-analyzer/tests/slow-tests/support.rs
+++ b/crates/rust-analyzer/tests/slow-tests/support.rs
@@ -103,6 +103,7 @@ impl Project<'_> {
                 filter: std::env::var("RA_LOG").ok().unwrap_or_else(|| "error".to_owned()),
                 chalk_filter: std::env::var("CHALK_DEBUG").ok(),
                 profile_filter: std::env::var("RA_PROFILE").ok(),
+                json_profile_filter: std::env::var("RA_PROFILE_JSON").ok(),
             };
         });