Stream: t-compiler/wg-rls-2.0

Topic: Decreased performance and lots of logging visible in VsCode


Matthias247 (May 11 2020 at 17:01, on Zulip):

Hi everyone!
Since the last 2 weeks or so RA performance degraded for me so bad that it's unusable at the moment (100% CPU load for multiple minutes, repeats as I click/hover anything). I'm not yet sure if the degradation came through a recent update, or due me opening a different workspace.

What I've seen so far is however that there is a lot of debug output visible in the VsCode -> Output -> "Rust Analyzer Language Server" tab. I'm wondering if that all should be there, or whether it was accidentally enabled through some way. Excessive logging could obviously degrade performance.

Some examples:

[DEBUG salsa::derived::slot] maybe_changed_since(AstIdMapQuery(HirFileId(MacroFile(MacroFile { macro_call_id: LazyMacro(LazyMacroId(13902)) }))): false since (recomputed) value changed at R17080
[DEBUG salsa::derived::slot] maybe_changed_since(ParseMacroQuery(MacroFile { macro_call_id: LazyMacro(LazyMacroId(13902)) })) called with revision=R17080, revision_now=R17084
[DEBUG salsa::derived::slot] maybe_changed_since(ParseMacroQuery(MacroFile { macro_call_id: LazyMacro(LazyMacroId(13902)) }): false since up-to-date memo that changed at R17080
[INFO  salsa::derived::slot] RawItemsQuery(HirFileId(MacroFile(MacroFile { macro_call_id: LazyMacro(LazyMacroId(13902)) }))): validated old memoized value
[DEBUG salsa::runtime] is_current_revision_canceled: current_revision=R17084, pending_revision=R17084
[DEBUG salsa::derived::slot] maybe_changed_since(RawItemsQuery(HirFileId(MacroFile(MacroFile { macro_call_id: LazyMacro(LazyMacroId(13902)) }))): false since (recomputed) value changed at R17080
[DEBUG salsa::derived::slot] maybe_changed_since(RawItemsQuery(HirFileId(MacroFile(MacroFile { macro_call_id: LazyMacro(LazyMacroId(13903)) })))) called with revision=R17080, revision_now=R17084
[DEBUG salsa::derived::slot] check_durability(last_changed=R17084 <= verified_at=R17080) = false
[DEBUG salsa::derived::slot] RawItemsQuery(HirFileId(MacroFile(MacroFile { macro_call_id: LazyMacro(LazyMacroId(13903)) }))): read_upgrade(revision_now=R17084)
[DEBUG salsa::derived::slot] RawItemsQuery(HirFileId(MacroFile(MacroFile { macro_call_id: LazyMacro(LazyMacroId(13903)) }))): found memoized value, verified_at=R17080, changed_at=R17080
[DEBUG salsa::derived::slot] validate_memoized_value(RawItemsQuery): verified_at=Tracked {

Is the debug logging level somehow set through my system (I can't find anything in RA settings) or part of the downloaded package?

matklad (May 11 2020 at 17:02, on Zulip):

I think you have RUST_LOG env variable set?

pksunkara (May 11 2020 at 17:03, on Zulip):

Do you have the RUST_LOG env var set? edit: @matklad is fast :slight_smile:

matklad (May 11 2020 at 17:03, on Zulip):

we use stock env_logger for logging

Matthias247 (May 11 2020 at 17:06, on Zulip):

Just between sending that and looking at the thread again I checked the same. It was indeed set within the VsCode console :O

Matthias247 (May 11 2020 at 17:07, on Zulip):

It seemed like I started VsCode on a terminal which had export RUST_LOG=debug set because I did some CLI testing with an app before

matklad (May 11 2020 at 17:07, on Zulip):

We might show an info message if RUST_LOG=debug is enabled...

Matthias247 (May 11 2020 at 17:08, on Zulip):

Closing Code, and starting it on a new terminal without env variable fixed the perf issue :tada:

Matthias247 (May 11 2020 at 17:10, on Zulip):

@matklad Might it be worth it not to use the RUST_LOG variable from the environment variable but instead just from a RA setting?

Matthias247 (May 11 2020 at 17:10, on Zulip):

That could avoid that kind of "surprise"

Matthias247 (May 11 2020 at 17:11, on Zulip):

I probably had the same terminal open with the debug variable set for weeks, since I'm reusing the terminal to open the workspace :rolling_eyes:

matklad (May 11 2020 at 17:16, on Zulip):

@Matthias247 good suggestion, impled in https://github.com/rust-analyzer/rust-analyzer/pull/4424

Matthias247 (May 11 2020 at 17:26, on Zulip):

Awesome! Thanks for taking it into account

Last update: Sep 30 2020 at 16:45UTC