wat_server uses 100% CPU

[samestep]

This is a followup on g-plane/vscode-wasm#4. First I cloned this repo at commit 212e1e8 into ~/github/g-plane/wasm-language-tools, ran cargo build --release, and put the following script named wat_server on my PATH:

#!/usr/bin/env bash
tee ~/github/g-plane/wasm-language-tools/input.txt | ~/github/g-plane/wasm-language-tools/target/release/wat_server

I then used that script via version 1.5.6 of the WebAssembly Language Tools VS Code extension to generate an input.txt file to make this issue reproducible. After I closed that VS Code window, the wat_server process remained running while using 100% of one of my cores, so I manually terminated it.

Finally, I reproduced the issue by running cat input.txt | cargo run --release, which again produced a running wat_server process using 100% of one of my cores. In that case I was able to terminate the process via ^C since it was just in my terminal.

[g-plane]

Can it be reproduced by using cargo run (without --release)? Also, what's in input.txt?

[samestep]

You can click on the input.txt link above to download the file; here's the text of the link, in case that's easier: https://github.com/user-attachments/files/18691940/input.txt

And yes, cat input.txt | cargo run uses 100% of a core even without --release.

[g-plane]

I can't reproduce. When I run such command, wat_server only consumes about 5%. (CPU: Intel i7-12700K)

[samestep]

Sounds like a reproduction to me? The macOS Activity Monitor reports percentage of a core rather than of the entire CPU, so if your percentage is of the entire CPU, then 12 cores translates to roughly 60% of a core, which is still way more than the 0% it should be using after receiving a shutdown message.

[g-plane]

I may have ideas and I will investigate tomorrow.

[g-plane]

Does this problem only occur after receving shutdown message? Or even after initializing?

[samestep]

I haven't done that detailed debugging yet so I'm not sure; if I were to look more into it right now, the first thing I'd try would be to cut out some number of messages from the end of input.txt to see how many it takes before the CPU usage goes up.

[samestep]

OK, I did a bit more digging. One interesting thing to note is that, while VS Code seems to always send the shutdown request, it doesn't always send the exit notification afterward. For instance, if the extension is stopped by closing VS Code entirely, it will just send shutdown and then close the connection without bothering to wait for a response.

It seems that wat_server simply refuses to terminate until it receives that exit notification. I believe that was why I had to use ^C to terminate it in the example I gave above, even though it had already received the shutdown request. I tried a similar experiment with rust-analyzer, where I captured and replayed the log from a session where I just closed the VS Code window; instead of just keeping the process running, it terminated after shutdown (although it did also print a big error message).

I did an experiment with your VS Code extension in which I changed the restart command from calling client.restart() to calling client.stop(), and tried manually running that command instead of just closing the VS Code window. When I did that, the wat_server process disappeared as expected. It also exited just fine after I saved and replayed the log from that session as described above, since that log included the exit notification.

So, it seems that at least one issue is that wat_server doesn't terminate until it receives an exit notification. It should instead terminate if the connection closes, even if it hasn't yet received the exit notification. However, this is not the entire issue: even if I remove the shutdown request from the end of the log and replay it to wat_server, the CPU usage still goes up to 100% of a core. But I'm not sure if I can reproduce that in VS Code while the extension is still running, so it's possible that the only real issue is not terminating when the connection closes.

[samestep]

I opened #12 since keeping the process running when the input channel closes is a distinct issue. I've left this issue open as well in case the CPU usage is unrelated, but if it's resolved after fixing #12, obviously feel free to just close both.

[g-plane]

I'm not sure if it's helpful, but do you have conditions to test on other systems? I don't have a Mac. (It's okay for you to say no.)

[samestep]

I haven't tried it on other systems, but I can if you need me to. Just to clarify: are you saying that when you run this on your machine, the CPU usage stabilizes at 0%? Because as I said before, if your wat_server CPU usage stabilizes at a nonzero percentage when you run this, it seems like you've successfully reproduced it.

[g-plane]

I think I reproduced it. As a language server, it shouldn't consume 5% CPU.

[g-plane]

instead of just keeping the process running, it terminated after shutdown (although it did also print a big error message)

This is my previous implementation. Once I encountered the error message, I decided to not exit until receiving exit message. Maybe we can use a timer.

[samestep]

If the connection closes, the language server should terminate. You can print an error or not depending on your preference I suppose, but it's definitely incorrect for the language server to keep running, even on a timer. Unless I'm misunderstanding something?

[samestep]

As another data point, take a look at the implementation in the lsp-server library, which rust-analyzer uses: https://github.com/rust-lang/rust-analyzer/blob/2025-02-03/lib/lsp-server/src/lib.rs#L354

Upon receiving a shutdown message, it does start a 30-second timer while waiting for the exit message, which sounds similar to what you're proposing. But, crucially, if the connection closes, it doesn't end up waiting 30 seconds: it just immediately returns an error saying "channel disconnected waiting for exit notification" because if the connection is closed then waiting is never going to give anything.

(Also, just to clarify: while rust-analyzer uses that library, it doesn't call that specific function I linked above, and instead does its own thing that doesn't have a timeout, as far as I'm aware. But the point is, in both cases, there's no waiting around after the connection closes.)

[g-plane]

Solution may fix these two issues.