Rust-analyzer debug logs in VS Code

dbeckwith · August 15, 2023, 10:15pm

I use the official rust-analyzer extension in VS Code, which works great most of the time. However, occasionally the status bar item for RA will show a warning or error saying that it failed to compile some packages or something. When I click on the status bar item or choose the "Open logs" menu item, it brings up the VS Code Output window with the Rust Analyzer Language Server selected. I expect to find something actionable in these logs, but it just seems entirely filled with very verbose debug output that I can't see any value in. Here's a snippet:

[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(10))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(10))): returning memoized value changed at R17268    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(10))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(10))): returning memoized value changed at R17268    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6522))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6522))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6522))): invoked at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6522))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6523)): invoked at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6523)): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(10))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(10))): returning memoized value changed at R17268    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(10))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(10))): returning memoized value changed at R17268    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6523))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6523))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6523))): invoked at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6523))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(10))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(10))): returning memoized value changed at R17268    
[INFO salsa::derived::slot] TraitSolveQueryQuery((Idx::<CrateData>(332), None, Canonical { value: InEnvironment { environment: Env([]), goal: Implemented(AdtId(EnumId(EnumId(46)))<[?0 := AdtId(StructId(StructId(477)))<[]>, ?1 := AdtId(StructId(StructId(3196)))<[]>]>: TraitId(10)) }, binders: [] })): invoked at R39535    
[INFO salsa::derived::slot] TraitSolveQueryQuery((Idx::<CrateData>(332), None, Canonical { value: InEnvironment { environment: Env([]), goal: Implemented(AdtId(EnumId(EnumId(46)))<[?0 := AdtId(StructId(StructId(477)))<[]>, ?1 := AdtId(StructId(StructId(3196)))<[]>]>: TraitId(10)) }, binders: [] })): returning memoized value changed at R39535    
[INFO salsa::derived::slot] TraitDataQuery(TraitId(199)): invoked at R39535    
[INFO salsa::derived::slot] TraitDataQuery(TraitId(199)): returning memoized value changed at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6855)): invoked at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6855)): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(199))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(199))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(199))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(199))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6855))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6855))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6855))): invoked at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6855))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6856)): invoked at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6856)): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(199))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(199))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(199))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(199))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6856))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6856))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6856))): invoked at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6856))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] TraitDataQuery(TraitId(68)): invoked at R39535    
[INFO salsa::derived::slot] TraitDataQuery(TraitId(68)): returning memoized value changed at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6540)): invoked at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6540)): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(68))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(68))): returning memoized value changed at R17268    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(68))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(68))): returning memoized value changed at R17268    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6540))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6540))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6540))): invoked at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6540))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] TraitDataQuery(TraitId(65)): invoked at R39535    
[INFO salsa::derived::slot] TraitDataQuery(TraitId(65)): returning memoized value changed at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6531)): invoked at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6531)): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(65))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(65))): returning memoized value changed at R17268    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(65))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(65))): returning memoized value changed at R17268    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6531))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(6531))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6531))): invoked at R39535    
[INFO salsa::derived::slot] CallableItemSignatureQuery(FunctionId(FunctionId(6531))): returning memoized value changed at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(65))): invoked at R39535    
[INFO salsa::derived::slot] GenericParamsQuery(TraitId(TraitId(65))): returning memoized value changed at R17268    
[INFO salsa::derived::slot] TraitSolveQueryQuery((Idx::<CrateData>(332), None, Canonical { value: InEnvironment { environment: Env([]), goal: Implemented(AdtId(EnumId(EnumId(46)))<[?0 := AdtId(StructId(StructId(477)))<[]>, ?1 := AdtId(StructId(StructId(3196)))<[]>]>: TraitId(65)) }, binders: [] })): invoked at R39535    
[INFO salsa::derived::slot] TraitSolveQueryQuery((Idx::<CrateData>(332), None, Canonical { value: InEnvironment { environment: Env([]), goal: Implemented(AdtId(EnumId(EnumId(46)))<[?0 := AdtId(StructId(StructId(477)))<[]>, ?1 := AdtId(StructId(StructId(3196)))<[]>]>: TraitId(65)) }, binders: [] })): returning memoized value changed at R39535    
[INFO salsa::derived::slot] TraitDataQuery(TraitId(111)): invoked at R39535    
[INFO salsa::derived::slot] TraitDataQuery(TraitId(111)): returning memoized value changed at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6533)): invoked at R39535    
[INFO salsa::derived::slot] FunctionDataQuery(FunctionId(6533)): returning memoized value changed at R39535

Either this isn't showing the right log file, or I can't figure out how to find any useful warning/error messages in here. I've tried in the past searching for "ERROR" and things like that, but the content seems to be missing from this output stream. There's another Output tab called Rust Analyzer Language Server Trace but that's even more verbose and again doesn't seem to have any basic output messages in it.

Does anyone who uses VS Code know where I can find useful output logs from RA for troubleshooting build issues?

nerditation · August 16, 2023, 1:31am

those are log for the rust-analyzer developers to diagnose RA itself. you must have the RA_LOG environment variable set to DEBUG or something. they are too verbose that they overflow vscode's scrollback buffer.

for normal users, just leave it default (ERROR I think, not sure). if for some reason you need those verbose logs, try log it to a file by setting the RA_LOG_FILE env and search for errors in the log file.

btw, if RA can't load due to build failure (instead of bug of RA itself), typically you can simply run cargo build or cargo check manually and it should report the build errors. you only need to check RA log messages for build errors if the build process involves uncommon steps that RA can't understand or need special configuration.

dbeckwith · August 18, 2023, 12:48am

Indeed, I had set RA_LOG to info in my VS Code settings and forgot about it. Removing that, I can now see useful info in the logs. IMO for info level it sends an excessive amount of output. Thank you!

nerditation · August 18, 2023, 6:25am

it depends on perspective. unless you are contributing to RA itself, or you are interested the internal works of RA, it should be unnecessary to set RA_LOG for daily uses.

RA is a tool for developers, the logs are mostly for the developers of the tool to troubleshoot RA itself, although the logs (especially high severity levels) might also be interesting to the users of RA (who happen to be rust developers too), users mainly interact with the output (as oppose to the logs) of the tool, and most of time it is handled by a LSP client.

system · November 16, 2023, 6:26am

This topic was automatically closed 90 days after the last reply. We invite you to open a new topic if you have further questions or comments.