100% CPU usage

[tsvallender]

Description

I am fairly regularly (probably about once a day at a full-time job) having ruby-lsp hit 100% CPU and stay there until I restart the process. I’m using the latest ruby-lsp with the Rails extension, in Neovim. I’ve seen this behaviour in multiple Ruby versions but am mostly in 3.3.4 currently.

I’m more than happy to do some work trying to figure out what’s causing this but am unsure where to start, any pointers appreciated.

[andyw8]

@tsvallender if you are able to share the LSP logs from just before it causes the CPU to peak, then that may help us to diagnose the problem.

Also, are you are on the latest release? (v0.17.13)

[tsvallender]

@tsvallender if you are able to the LSP logs from just before it causes the CPU to peak, then that may help us to diagnose the problem.

Also, are you are on the latest release? (v0.17.13)

There hasn't been anything extra in the logs, and yes latest release. A colleague suggested stracing the process next time it happens so will see if that suggests anything. Always the way it doesn't happen when you're waiting for it...

[Earlopain]

I've had a hang somewhat recently (like maybe 1 month ago) as well but strace didn't show a thing. Process just kept doing things even after vscode was gone. Seems like this happens relativly often for you. How about you try adding the following to the ruby-lsp script:

Signal.trap("SIGUSR1") do
  output = +""
  Thread.list.each do |thr|
    output << ("-" * 40) << "\n"
    output << thr.inspect << "\n"
    output << thr.backtrace.join("\n") << "\n"
  end
  File.write("ruby-lsp-trace.log", output)
end if Signal.list.include?("USR1")

You can then do kill -USR1 pid where pid is somewhere in the output from ps -aux | grep ruby-lsp. I'm not sure how useful the output would actually be, its just something I used elsewhere. This should create a file with backtraces in the root of the project as long as you are not on windows.

This is all a bit awkward with the server auto-updating and all that, I wonder if this would be a generally useful addition for debugging things like this. There have been a few other issues with CPU pegging as their topic.

[tsvallender]

So it’s happened again, strace output is:

strace: Process 96120 attached with 5 threads
[pid 96259] wait4(96258,  <unfinished ...>
[pid 96256] futex(0x2d26bd40, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY <unfinished ...>
[pid 96239] epoll_wait(4,  <unfinished ...>
[pid 96120] read(0,

which is nigh-on ungrokkable to me I’m afraid, is it of any use to anyone else?

I've had a hang somewhat recently (like maybe 1 month ago) as well but strace didn't show a thing. Process just kept doing things even after vscode was gone. Seems like this happens relativly often for you. How about you try adding the following to the ruby-lsp script: …

Great idea, I’ve just added that and verified it’s working so will try it next time…

[tsvallender]

Okay, so with that bit of code added in, I get the below, which to me seems to be pointing at this loop becoming infinite?

----------------------------------------
#<Thread:0x00007f2b0aa2a9e0 run>
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/base_server.rb:28:in `backtrace'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/base_server.rb:28:in `block (2 levels) in initialize'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/base_server.rb:25:in `each'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/base_server.rb:25:in `block in initialize'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/language_server-protocol-3.17.0.3/lib/language_server/protocol/transport/io/reader.rb:16:in `gets'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/language_server-protocol-3.17.0.3/lib/language_server/protocol/transport/io/reader.rb:16:in `read'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/base_server.rb:48:in `start'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/sorbet-runtime-0.5.11525/lib/types/private/methods/_methods.rb:279:in `bind_call'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/sorbet-runtime-0.5.11525/lib/types/private/methods/_methods.rb:279:in `block in _on_method_added'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/exe/ruby-lsp:135:in `<top (required)>'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/bin/ruby-lsp:25:in `load'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/bin/ruby-lsp:25:in `<top (required)>'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/cli/exec.rb:58:in `load'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/cli/exec.rb:58:in `kernel_load'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/cli/exec.rb:23:in `run'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/cli.rb:451:in `exec'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/vendor/thor/lib/thor/command.rb:28:in `run'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/vendor/thor/lib/thor.rb:527:in `dispatch'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/cli.rb:34:in `dispatch'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/vendor/thor/lib/thor/base.rb:584:in `start'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/cli.rb:28:in `start'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/exe/bundle:28:in `block in <top (required)>'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/bundler-2.5.5/exe/bundle:20:in `<top (required)>'
/home/tsv/.rbenv/versions/3.3.4/bin/bundle:25:in `load'
/home/tsv/.rbenv/versions/3.3.4/bin/bundle:25:in `<main>'
----------------------------------------
#<Thread:0x00007f2aee8307c8 /home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/base_server.rb:124 run>
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/document.rb:236:in `=='
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/document.rb:236:in `=='
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/document.rb:236:in `find_char_position'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/document.rb:114:in `locate_node'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/requests/signature_help.rb:54:in `initialize'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/sorbet-runtime-0.5.11525/lib/types/private/abstract/declare.rb:37:in `new'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/sorbet-runtime-0.5.11525/lib/types/private/abstract/declare.rb:37:in `block in declare_abstract'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/server.rb:638:in `text_document_signature_help'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/server.rb:68:in `process_message'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/base_server.rb:137:in `block in new_worker'
----------------------------------------
#<Thread:0x00007f2aee8afd20 /home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/base_server.rb:33 sleep_forever>
<internal:thread_sync>:18:in `pop'
/home/tsv/.rbenv/versions/3.3.4/lib64/ruby/gems/3.3.0/gems/ruby-lsp-0.17.13/lib/ruby_lsp/base_server.rb:35:in `block in initialize'
----------------------------------------
#<Process::Waiter:0x00007f2aeeba6600 sleep>

[Earlopain]

Certainly looks like something that could happen there, thought the only way I can think of is when edits are received out-of-order.

I coincidentally had another case today myself, though I failed to capture a stacktrace (oops). I'm going to add some logging to that method should we be running into the same thing.

[vinistock]

We received other reports of this and the thread is quite helpful. The referenced loop essentially turns a line + character position into the index that represents that position in the string we use to store the document's source code.

I'm not sure how we wouldn't be able to find the requested line and end up in an infinite loop though. We process text edits under a mutex lock, exactly to avoid having a feature request like signature help landing in between a thread switch (and thus trying to execute in a partially updated document).

If anyone can reproduce this reliably, we need to understand what piece of code triggers the problem.

Alternatively, we can also raise from that method if we reached the end of the document without finding anything and then include the state of the document and the position we were looking for. That might help diagnose it.

[adam12]

I've been chasing this one for a few months now as well. An alternative method I've used to capture the stack trace reliably is the rbspy tool.

I've observed two things when this has triggered:

1. Many times the ruby-lsp process has no ppid (parent). I am not sure this is connected tho.
2. Frequently, the task eventually completes and CPU usage returns to normal, so it's not likely to be an infinite loop.

I theorized that we were thrashing the GC somehow but wasn't able to get any deeper. It's near impossible to trigger by hand or via ruby-lsp doctor. It would be nice to be able to get Vernier enabled in a reproduction to see what the GC activity is like in order to rule it out.

[denvermullets]

if it's helpful, this triggers on my machine almost always now - to the point i've had to uninstall and i reinstall when i see an update is pushed - but if there are commands or anything that you would like me to run to help diagnose i am more than willing to help.

i'm on an intel mac still, if that matters. i uninstalled it because i just got tired of it melting my battery down so quickly with bash processes that run 100%.

[vinistock]

I think adding an explicit error message if the scanner fails to find the right position will help diagnose this. I'll put something up for this.

@denvermullets meanwhile, a few questions to try to understand what's going on:

1. What editor are you using?
2. What's the editor's encoding? UTF-8, UTF-16 or UTF-32?
3. Which line breaks do you use? \n or \r\n?
4. Do you notice this happening when doing something specific in your code? Like for example, does it always happen when you use multibyte characters like emojis or japanese characters?

[denvermullets]

@denvermullets meanwhile, a few questions to try to understand what's going on:

1. What editor are you using?
2. What's the editor's encoding? UTF-8, UTF-16 or UTF-32?
3. Which line breaks do you use? \n or \r\n?
4. Do you notice this happening when doing something specific in your code? Like for example, does it always happen when you use multibyte characters like emojis or japanese characters?

sorry, missed this.

1. VS Code
2. UTF-8
3. none, the only line breaks in the small repos i see it happening only have the default \n in the rails setup files
4. i'm doing neither of those options

[Earlopain]

I've just had this happen to me again and the window I had open at the time was a git diff, and that file is just boring utf8. I noticed this while benchmarking and the average went way up so I'm confident it happened then.

I unfortunatly had no way to debug this since the server updated and I didn't put my things back in. strace only showed this: futex(0x563c18caca04, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY, same as above.

[Aesthetikx]

This one happens to me essentially every day, neovim, M2 MacOS. I can help diagnose if someone points me in the right direction, no strace on MacOS so I can take a look with dtrace or equivalent perhaps.

[adam12]

I think it would be handy if anyone sees it again to capture a recent stacktrace. Looking at the stacktrace above, it seems a bit out of date.

[Aesthetikx]

I think it would be handy if anyone sees it again to capture a recent stacktrace. Looking at the stacktrace above, it seems a bit out of date.

I can reliably reproduce this, my only issue is I only run MacOS and BSD at the moment, I'll see if I can get this going on a Linux box with strace. Maybe I'll see you in IRC later @adam12

[adam12]

my only issue is I only run MacOS and BSD at the moment

Yeah, Mac ruined strace/dtruss didn't they :( You can install rbspy via Homebrew and run it against a running process.

sudo rbspy record -p <pid>

I've found this mechanism the most reliable.

Maybe I'll see you in IRC later

I'm around :sunglasses:

[Aesthetikx]

I'll see if I can get this with a more up to date ruby-lsp, although I'm having trouble tricking neovim into using the latest version for some reason.

Time since start: 19s. Press Ctrl+C to stop.
Summary of profiling data so far:
% self  % total  name
 71.23    71.23  == [c function] - (unknown)
 28.77   100.00  find_char_position - /Users/john/.rbenv/versions/3.1.6/lib/ruby/gems/3.1.0/gems/ruby-lsp-0.17.2/lib/ruby_lsp/document.rb:240
  0.00   100.00  text_document_completion - /Users/john/.rbenv/versions/3.1.6/lib/ruby/gems/3.1.0/gems/ruby-lsp-0.17.2/lib/ruby_lsp/server.rb:560
  0.00   100.00  process_message - /Users/john/.rbenv/versions/3.1.6/lib/ruby/gems/3.1.0/gems/ruby-lsp-0.17.2/lib/ruby_lsp/server.rb:89
  0.00   100.00  new [c function] - (unknown)
  0.00   100.00  initialize - /Users/john/.rbenv/versions/3.1.6/lib/ruby/gems/3.1.0/gems/ruby-lsp-0.17.2/lib/ruby_lsp/requests/completion.rb:105
  0.00   100.00  block in new_worker - /Users/john/.rbenv/versions/3.1.6/lib/ruby/gems/3.1.0/gems/ruby-lsp-0.17.2/lib/ruby_lsp/base_server.rb:130
  0.00   100.00  block in declare_abstract - /Users/john/.rbenv/versions/3.1.6/lib/ruby/gems/3.1.0/gems/sorbet-runtime-0.5.11592/lib/types/private/abstract/declare.rb:42

[adam12]

Another idea might be running with --debug and see if you can get rdbg to break into the process once it triggers the 100% CPU scenario. Then perhaps do a bit of poking around (like @source, @pos, and @encoding might be of value).

I have been running with --debug for a few weeks now but either haven't seen the 100% CPU scenario with frequency and at least once, I could, but rdbg didn't see the socket.

Here's my Lua config.

local lspconfig = require('lspconfig')
lspconfig.ruby_lsp.setup({
  cmd = { 'ruby-lsp', '--debug', },
})

You'll want rdbg -A to break into the process.

[vinistock]

I'm still puzzled by this, but if people are willing to help diagnose this PR https://github.com/Shopify/ruby-lsp/pull/2664 has a bit more machinery to help.

Essentially, if the scanner fails to find the requested position, then we raise and print to the output tab the document state and the requested position that caused the failure. This should hopefully help us understand if the document state got corrupted.

To test on that branch, I believe it would be enough to put the ruby-lsp gem in the Gemfile and point to it.

[tsvallender]

Possibly of note is that I changed machine recently, and haven't had this issue since, despite having the same Neovim setup. So one fix is to buy a new PC 😅

[Aesthetikx]

I'll post another update if I see it, but I actually think updating to the latest ruby-lsp fixed this. I wasn't aware that my vim distribution vendored it's own version of the gem, hence I was not on the latest version that was installed globally or in my Gemfiles.

[andyw8]

@Aesthetikx which vim distribution is that?

[Aesthetikx]

@Aesthetikx which vim distribution is that?

@andyw8

In this particular case LazyVim, which I do update regularly, I think however the issue is that it is not part of the LazyVim update screen, it is :Mason and then you can update the underlying LSP dependencies from there, which is why I was out of date. As for why it doesn't use a local version of ruby-lsp, who's to say?

[andyw8]

I'm not familiar with LazyVim or Mason, but there is an example config here that might help:

https://shopify.github.io/ruby-lsp/editors.html#lazyvim-lsp

[miguno]

I have been sporadically running into this problem, too. I have not yet been able to reproduce it, however.

• macOS 15.0.1 Sequoia on a 2021 MBP Pro
• ruby-lsp 0.20.1
• Ruby 3.3.5
• Rails v8 (pre-release, directly from main)

$ nvim --version
NVIM v0.10.0
Build type: Release
LuaJIT 2.1.1713484068
Run "nvim -V1 -v" for more info

[denvermullets]

i spent a few hours this morning trying to resolve this and noticed that it's stuck on starting:

i'm using asdf w/vs code and have been trying different settings to see if there's a connection there. i also tried updating my current project to ruby 3.3.5 (was on 3.3.0) and just updated my mac last night to the latest os.

i do not have this problem on my work computer which is an M1 vs my personal laptop which is an intel. unsure how that'd be related but just something i've noticed.

edit: i'm dumb i didn't realize i had to select the tab and then the dropdown in output to get the error so maybe my error isn't fit for this issue:

2024-10-30 11:27:36.183 [info] (myproject) Checking if chruby is available on the path with command: /bin/zsh -i -c 'chruby --version'
2024-10-30 11:27:39.990 [info] (myproject) Checking if rbenv is available on the path with command: /bin/zsh -i -c 'rbenv --version'
2024-10-30 11:27:43.711 [info] (myproject) Checking if rvm is available on the path with command: /bin/zsh -i -c 'rvm --version'
2024-10-30 11:27:47.378 [info] (myproject) Checking if asdf is available on the path with command: /bin/zsh -i -c 'asdf --version'
2024-10-30 11:27:51.247 [info] (myproject) Discovered version manager none
2024-10-30 11:27:51.247 [info] (myproject) Running command: `ruby -W0 -rjson -e 'STDERR.print("RUBY_LSP_ACTIVATION_SEPARATOR" + { env: ENV.to_h, yjit: !!defined?(RubyVM:: YJIT), version: RUBY_VERSION, gemPath: Gem.path }.to_json + "RUBY_LSP_ACTIVATION_SEPARATOR")'` in /Users/denvermullets/Development/pers/myproject using shell: /usr/local/bin/zsh

it never returns from this unless i force quit the bash process that's 100%'ing

[soda92]

I have get high CPU problem too, don't know if it's the same.

On windows 10 with neovim+ruby lsp

When I fire up two neovim instances editing Ruby code (so there are two ruby-lsp running), there starts to be ruby process consuming high CPU.

these processes exist even after exited neovim.

Also it's hard to kill them it seems they are spawn each other

[nanafox]

I'm not familiar with LazyVim or Mason, but there is an example config here that might help:

https://shopify.github.io/ruby-lsp/editors.html#lazyvim-lsp Thanks for this @andyw8

I followed the recommendation and added the config. I'll keep monitoring the behavior now to see how this helps. But so far, it's not behaving as it used to (at least, for now). The only time I saw a spike was during the initial startup, after which CPU utilization went back to normal.

[sathishmanohar]

I ran across this issue today. I can replicate it like this. I have the below rails model file open

class Some < ApplicationRecord
  include SecureTokenId

  validates :content, presence: true
end

and then I paste in

class Some < ApplicationRecord
  include SecureTokenId
  
  STATES = %w[requested responded approved].freeze
  
  validates :state, inclusion: { in: STATES }
  validates :content, presence: true, if: :content_required?

  private

  def content_required?
    %w[responded approved].include?(state)
  end
end

Nothing happens just yet (checked the CPU usage at this step. It is normal). As soon as I do :Neoformat to format the buffer using rubocop. ruby_lsp takes up 100% of one CPU thread.

More info

nvim --version
NVIM v0.10.2
Build type: RelWithDebInfo
LuaJIT 2.1.1731601260
Run "nvim -V1 -v" for more info

[andyw8]

@sathishmanohar I'm not familiar with Neoformat, but it doesn't seem like it supports LSP tooling: https://github.com/sbdchd/neoformat/issues/400