Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Hanging LSP requests on Corrosion (Eclipse) #14146

Open
lnicola opened this issue Feb 14, 2023 · 12 comments
Open

Hanging LSP requests on Corrosion (Eclipse) #14146

lnicola opened this issue Feb 14, 2023 · 12 comments
Labels
A-third-party-client C-bug Category: bug C-support Category: support questions S-unactionable Issue requires feedback, design decisions or is blocked on other work

Comments

@lnicola
Copy link
Member

lnicola commented Feb 14, 2023

For me this isn't fixed in Eclipse with rust-analyzer 0.3.1394-standalone (0b32b65ca 2023-02-05) from https://github.com/rust-lang/rust-analyzer/releases/tag/2023-02-06 (downloaded rust-analyzer-x86_64-pc-windows-msvc.zip and extracted so that i have D:\Users\Hydra\.local\bin\rust-analyzer.exe and the IDE is configured to use that specific file. Old version /without/ the .exe extension that Eclipse downloads and extracts is deleted to be sure.

It's certainly better, but it still dies and in Eclipse 2/ Corrosion the end user experiance is that the IDE shows a 'Language Background Server Job' that never completes, task manager shows multiple instances of 'rust-analyzer.exe' and hover-over always fails with two errors in the IDE log:

image

image

image

Could not get hover region due to timeout after 500 miliseconds

java.util.concurrent.TimeoutException
	at java.base/java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1960)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2095)
	at org.eclipse.lsp4e.operations.hover.LSPTextHover.getHoverRegion(LSPTextHover.java:152)
...

and

Could not get hover information due to timeout after 500 miliseconds

java.util.concurrent.TimeoutException
	at java.base/java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1960)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2095)
	at org.eclipse.lsp4e.operations.hover.LSPTextHover.getHoverInfo(LSPTextHover.java:73)
...

Version details:

rust-analyzer 0.3.1394-standalone (0b32b65ca 2023-02-05)
Eclipse IDE for Embedded C/C++ Developers	4.26.0.20221201-1200	epp.package.embedcpp	Eclipse Packaging Project
Corrosion: Rust edition in Eclipse IDE	1.2.5.202209271915	org.eclipse.corrosion.feature.feature.group	Eclipse Corrosion

Originally posted by @hydra in #10910 (comment)

@hydra
Copy link

hydra commented Feb 14, 2023

@lnicola thanks for opening this.

Yeah, see RA_LOG=info here. Eclipse might also have a log window, I don't know.

I tried that, by setting a windows environment variable before opening eclipse, as follows:

image

But this causes Eclipse to become completely unresponsive and there is a stuck rust-analyzer in the task manager, which when killed unfreezes eclipse which results in this:

image

@hydra
Copy link

hydra commented Feb 14, 2023

For reference my Eclipse IDE rust settings look like this:

image

Note the 'language server' setting end /with/ a .exe as I manually grabbed the latest release of rust analyzer and manually extracted it to that path, removing the old one /without/ the .exe suffix that Eclipse downloads (see also eclipse-corrosion/corrosion#410)

Release: https://github.com/rust-lang/rust-analyzer/releases/tag/2023-02-06

rust-analyzer 0.3.1394-standalone (0b32b65ca 2023-02-05)

@lnicola
Copy link
Member Author

lnicola commented Feb 14, 2023

Humm.. What if you also set RA_LOG_FILE to some file (might want to use an absolute path if you're setting it like that).

@hydra
Copy link

hydra commented Feb 14, 2023

Interesting when I set this, it doesn't seem to be stalling after opening about 50 different files...

image

RA_LOG_FILE=D:\Users\Hydra\.local\bin\rust-analyzer.log.txt

The log file is also a gargantuan 922MB!

@hydra
Copy link

hydra commented Feb 14, 2023

After a while though, the problem re-occurs:

image

image

I have a 675MB log saved here.

Here's the last 100 lines, via tail:

[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] FileItemTreeQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): invoked at R30924
[INFO salsa::derived::slot] AstIdMapQuery(HirFileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] ParseQuery(FileId(0)): invoked at R30924
[INFO salsa::derived::slot] ParseQuery(FileId(0)): returning memoized value changed at R13
[INFO salsa::derived::slot] BodyWithSourceMapQuery(FunctionId(FunctionId(25112))): invoked at R30924
[INFO salsa::derived::slot] BodyWithSourceMapQuery(FunctionId(FunctionId(25112))): returning memoized value changed at R30924
[INFO salsa::derived::slot] ExprScopesQuery(FunctionId(FunctionId(25112))): invoked at R30924
[INFO salsa::derived::slot] ExprScopesQuery(FunctionId(FunctionId(25112))): returning memoized value changed at R30924
[INFO salsa::derived::slot] CrateDefMapQueryQuery(CrateId(89)): invoked at R30924
[INFO salsa::derived::slot] CrateDefMapQueryQuery(CrateId(89)): returning memoized value changed at R30924
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(25112))): invoked at R30924
[INFO salsa::derived::slot] GenericParamsQuery(FunctionId(FunctionId(25112))): returning memoized value changed at R30924
[INFO salsa::derived::slot] ExprScopesQuery(FunctionId(FunctionId(25112))): invoked at R30924
[INFO salsa::derived::slot] ExprScopesQuery(FunctionId(FunctionId(25112))): returning memoized value changed at R30924
[INFO salsa::derived::slot] BlockDefMapQuery(BlockId(121)): invoked at R30924
[INFO salsa::derived::slot] BlockDefMapQuery(BlockId(121)): returning memoized value changed at R30924

@lnicola
Copy link
Member Author

lnicola commented Feb 14, 2023

I think RA_LOG=lsp_server=debug should give you only the LSP communication.

@hydra
Copy link

hydra commented Feb 14, 2023

I think RA_LOG=lsp_server=debug should give you only the LSP communication.

I did that, but it's not currently stalling, I do see log output though. When it stalls next I'll post the log.

@lnicola
Copy link
Member Author

lnicola commented Feb 14, 2023

Just to be sure, can you check that a different IDE works fine? And is your project public?

@hydra
Copy link

hydra commented Feb 14, 2023

@lnicola I guess I could try VS Code, I have it installed but haven't tried configuring it to use rust-analyzer yet, but I did see some instructions above the troubleshooting link you sent prior.

No, my main project is not public, it's a large codebase with many workspace crates, though I was having issues with tiny test/playground projects too.

At this point I'm wondering if there's a timing or threading related issue going on, I use a X5950 CPU with 32 threads, I say this because enabling logging to a single file likely causes thread synchronization if there are multiple threads, and/or will block due to blocking io which can also cause code to be executed in a different order.

Is it possible to limit rust-analyzer to use a single thread, or does it only use one thread anyway?

@lnicola
Copy link
Member Author

lnicola commented Feb 15, 2023

I have it installed but haven't tried configuring it to use rust-analyzer yet, but I did see some instructions above the troubleshooting link you sent prior.

Go to the extensions pane, install the extension. If you want to set some env variables, press Ctrl-., then set rust-analyzer.server.extraEnv to an object (dictionary).

At this point I'm wondering if there's a timing or threading related issue going on

Yeah, might be. You can also try to disable rust-analyzer.checkOnSave to take that out of the picture.

Is it possible to limit rust-analyzer to use a single thread, or does it only use one thread anyway?

It's a bit more complicated, but there's rust-analyzer.numThreads which you can set, which sets the main thread pool size. We do some pre-computation at start-up, which you can configure with rust-analyzer.cachePriming.numThreads and rust-analyzer.cachePriming.enable. I suspect disabling this might "fix" the issue.

a X5950 CPU with 32 threads

Yeah, I've got one of those too, it's not a reason to hang.


In addition, you can give rust-analyzer analysis-stats . a try. If it hangs, it makes things much easier.

@lnicola lnicola added S-unactionable Issue requires feedback, design decisions or is blocked on other work C-bug Category: bug C-support Category: support questions labels Feb 15, 2023
@hydra
Copy link

hydra commented Feb 15, 2023

Can you point me at the docs that explain how to make the configuration changes you describe above? Is there some configuration file somewhere that they are stored in?

Excuse me for being a noob when it comes to using rust-analyzer, I don't know how to change the settings for it as above, my experience with the tool only comes though the Eclipse Corrosion plugin which is a required installation for the tool and Eclipse Corrosion doesn't expose a UI for rust-analyzer configuration or give any real details about it so I'm kinda floundering in the dark a bit here.

For sure I can try the various settings you suggest, just need to know how to make the changes.

@lnicola
Copy link
Member Author

lnicola commented Feb 15, 2023

Can you point me at the docs that explain how to make the configuration changes you describe above?

For Corrosion? No idea, I've never used it. In Code, you can press Ctrl-. (I made a typo above) and edit the file it opens (it's a JSON, you can look at the defaults on the left side and you'll get completions).

And for rust-analyzer analysis-stats . you can just run it from a Command Prompt, but you might need to put in the full path to the binary.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-third-party-client C-bug Category: bug C-support Category: support questions S-unactionable Issue requires feedback, design decisions or is blocked on other work
Projects
None yet
Development

No branches or pull requests

3 participants