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

High CPU usage since 0.25.0 #733

Closed
ElvenSpellmaker opened this issue Dec 3, 2021 · 39 comments
Closed

High CPU usage since 0.25.0 #733

ElvenSpellmaker opened this issue Dec 3, 2021 · 39 comments
Labels
bug Something isn't working waiting-response

Comments

@ElvenSpellmaker
Copy link

ElvenSpellmaker commented Dec 3, 2021

Server Version

0.25.0

Terraform Version

v1.0.2

Client Version

VSCode 1.62.3

Terraform Configuration Files

N/A perhaps?

Log Output

There's lot of
2021/12/03 10:09:32 provider_schema.go:196: PSS: getting provider schema in the vscode console log and it seems to be going over and over the repo again and again looking at the whole repo (which has a lot of Terraform in it spread out all over the place)

Expected Behavior

It should work without high CPU

Actual Behavior

image

The CPU varies from 50-100% consistently while in TF files.

The log when I last copied it had 184491 lines.

Steps to Reproduce

Load some TF files in vscode since the latest update

@radeksimko
Copy link
Member

@ElvenSpellmaker Thanks for the report and sorry for the experience.

looking at the whole repo (which has a lot of Terraform in it spread out all over the place)

This indexing is generally by design e.g. to enable discovery of cross-module references.

It has a cap on parallelism, but that is mostly just to reduce the peak CPU usage, it just means the indexing will take longer at the cost of lower CPU usage. We have plans to potentially allow this cap to be configurable as per

I would say the easiest short-term solution, while we investigate, would be to open just a few relevant individual folders as opposed to the parent folder which contains many Terraform modules, or to set "requiredVersion": "0.24.0" in "terraform.languageServer" settings block in VS Code.

The log when I last copied it had 184491 lines.

I would be very interested in the log as it could show us the sequence of operations that happen as part of the indexing. Are you willing to share it? Feel free to encrypt it with my GPG key and send to radek<at>hashicorp.com if it's sensitive and you don't want to post it publicly.

@radeksimko radeksimko added bug Something isn't working waiting-response labels Dec 3, 2021
@ElvenSpellmaker
Copy link
Author

ElvenSpellmaker commented Dec 3, 2021

@ElvenSpellmaker Thanks for the report and sorry for the experience.

looking at the whole repo (which has a lot of Terraform in it spread out all over the place)

This indexing is generally by design e.g. to enable discovery of cross-module references.

Yeah I'd understand if it stopped after a while but it never stops, it's been at 50-100% CPU since I upgraded this morning at 8:42AM (now 10:40AM)

@ElvenSpellmaker
Copy link
Author

ElvenSpellmaker commented Dec 3, 2021

I'll get the file over to you

EDIT: I've just captured a file using "-log-file=C:\\Users\\JackBlower\\Documents\\terraform-ls-{{pid}}.log", and will get that over, this one is 44k lines so far.

@radeksimko
Copy link
Member

Thank you for sending over the log.

I don't yet entirely understand how that would relate to high CPU usage, but I have a hunch that the flood of the mentioned log messages may be related to the pre-computation of the reference count code lens where we basically attempt to find references across all (initialized) modules in the workspace. It's worth noting that these lookups are in-memory lookups so they should not consume any significant CPU, but it would likely explain the log messages.

Can you try setting "terraform.codelens.referenceCount" to false in your VS Code settings (only available in the latest extension release 2.17.0) and check the log/CPU again?

If this continues to be a problem - or either way - can you try to obtain the CPU profile and send it over?

@ElvenSpellmaker
Copy link
Author

I've tried CPU logging before and it always generates a 0 byte file

@radeksimko
Copy link
Member

To clarify the CPU profile is only generated once the editor/LS is shut down, until then it will have 0 bytes. Have you checked the file after closing the editor?

@ElvenSpellmaker
Copy link
Author

ElvenSpellmaker commented Dec 3, 2021

the reference count code lens where we basically attempt to find references across all (initialized) modules in the workspace

This project has multiple Terraform projects within it (essentially a monorepo) and so I'm not sure why it's trying to reference so many projects at once.
My editor has the whole repo open but only files from one "domain" at a time usually.

Can you try setting "terraform.codelens.referenceCount" to false in your VS Code settings (only available in the latest extension release 2.17.0) and check the log/CPU again?

Yeah this seems to be the main cause, it goes from about 50-100% to 10% with that setting as false, what do I lose by having that as false?
This only started being a problem in this version of the language server.

To clarify the CPU profile is only generated once the editor/LS is shut down, until then it will have 0 bytes. Have you checked the file after closing the editor?

Yeah it doesn't always populate when I close (although I did forget about that, thanks), I haven't been able to get it to populate with the referenceCount as true so far.

EDIT: (It was the same time last time there was a CPU bug, the CPU profiles don't generate while the hanging is present)

@ElvenSpellmaker
Copy link
Author

ElvenSpellmaker commented Dec 3, 2021

On one of my files I notice I'm not getting the 1 references count etc, could this be the file that's triggering the high CPU?

One file:
image

Another file:
image

@radeksimko
Copy link
Member

radeksimko commented Dec 3, 2021

It was the same time last time there was a CPU bug, the CPU profiles don't generate while the hanging is present

I suspect this may be related to the signal that is sent to the editor and/or the language server. It will not have any chance to write the CPU profile or do anything if it receives SIGKILL - at that point it's just being killed. You could try to find terraform-ls in the process list and try terminating it gracefully from there, or just open your terminal and do it from there:

$ ps -A | grep terraform-ls
78852 ??         0:04.11 /.../bin/terraform-ls serve
$ kill -INT 78852

On one of my files I notice I'm not getting the 1 references count etc

What you see on the top screenshot is the reference count "code lens", which should be disabled (for all files) and not shown if you have set terraform.codelens.referenceCount to false.

@ElvenSpellmaker
Copy link
Author

I assumed it was something like that, unfortunately as I'm on Windows I can't send the INT signal to the process, and taskkill will only kill it with /f enabled.

$ ps -W | grep terraform-ls
    79096       0       0      13560  ?              0 14:31:21 C:\Users\JackBlower\AppData\Roaming\Code\User\globalStorage\hashicorp.terraform\bin\terraform-ls.exe
$ kill -INT 79096
-bash: kill: (79096) - No such process
$ kill -INT 13560
-bash: kill: (13560) - No such process
taskkill /pid 13560
ERROR: The process with PID 13560 could not be terminated.
Reason: This process can only be terminated forcefully (with /F option).

@fishfacemcgee
Copy link

I'd like to chime in to say I'm seeing a similar increase in CPU usage/degradation in performance since 0.25.0 got installed. For instance, I'm seeing this CPU usage while the Terraform Formatter is attempting to run on save on a variables file with ~200 LoC and ~60 variables defined in it. It hangs like this for minutes before finishing, unless I cancel it first.

Screen Shot 2021-12-06 at 2 56 17 PM

@radeksimko
Copy link
Member

@fishfacemcgee Generally speaking the formatting has not really changed at all in the last release, so if you see problems with formatting then it would be a side effect of something else, like RPC request congestion.

Would you mind obtaining and sharing the CPU profile as per conversation above? You can send it to radek<at>hashicorp.com if you are worried about any sensitive data within it.

I really appreciate your reports here, but I'm afraid that I can't fix the bug if I can't reproduce it and/or obtain some more data to understand the root cause.

What would help is if you can provide a repro case in the form of module configuration which triggers this. Naturally more minimal is better. I understand @ElvenSpellmaker has a significant amount of modules in their workspace, if you could try to reduce the amount of modules you load into the workspace gradually and see at which point the bug is no longer getting triggered and share the relevant configuration which is triggering the bug - that would be great!

Alternatively/additionally I would also be willing to hop onto a Zoom session with anyone of you to do the debugging - feel free to book a slot via Calendly.

@bytejunkie
Copy link

ive just added a line to a map of 6 elements and tf formatter appears in the bottom right and stays and stays and stays. my macs fans spin up (so thats windows and mac) and it takes a few minutes to actually save.

if i see the issue persist, i'll jump on calendly, but just thought i'd add an early mention that this could be mac too.

@sidewinder12s
Copy link

I was also seeing it in a large monorepo but it really seemed to kick off on saves.

Playing with the the options above didn't seem to make a difference but I didn't remember yesterday that saves were what really triggered it.

@CorrenSoft
Copy link

Same situation here. Since I've installed this version, everything is dead (Hashicorp extension, the VSCode).
It is possible to make a downgrade?

@radeksimko
Copy link
Member

@bytejunkie @sidewinder12s @CorrenSoft Would you mind obtaining the CPU profile as per conversation above? You can send it to radekhashicorp.com if you are worried about any sensitive data within it.

@CorrenSoft You can pin to a particular version using "requiredVersion": "0.24.0" in terraform.languageServer settings block in VS Code.

@jpogran
Copy link
Contributor

jpogran commented Dec 7, 2021

In addition for those experiencing high cpu usage when formatting is running, can you paste the values for the following settings:

editor.defaultFormatter
editor.formatOnSave
editor.formatOnType
editor.formatOnPaste
editor.formatOnSaveMode
editor.codeActionsOnSave

If you have specified any settings specifically for the Terraform lanague (by setting "[terraform]":{}), please include those as well.

@bwmetcalf
Copy link

I believe this is the only thing I have set from the above:

    "[terraform]": {
        "editor.formatOnSave": true
    },

@fishfacemcgee
Copy link

Here's the entirety of my VS Code settings.json. Most of the options requested aren't there so they're using the defaults, which I'm including in a separate block at the bottom.

{
    "workbench.colorTheme": "Solarized Dark",
    "window.zoomLevel": 0,
    "editor.formatOnSave": true,
    "files.trimTrailingWhitespace": true,
    "files.insertFinalNewline": true,
    "shellcheck.run": "onSave",
    "files.trimFinalNewlines": true,
    "files.exclude": {
        "**/.terraform": true,
        "**/*.plan": true,
        "**/*.tfstate": true,
        "**/*.tfstate.*backup": true
    },
    "go.formatTool": "goimports",
    "go.useLanguageServer": true,
    "terraform.languageServer": {
        "external": true,
        "args": [
            "serve"
        ]
    },
    "workbench.editorAssociations": {
        "*.ipynb": "jupyter-notebook"
    },
    "editor.cursorStyle": "line",
    "editor.lineNumbers": "on",
    "editor.wordSeparators": "/\\()\"':,.;<>~!@#$%^&*|+=[]{}`?-",
    "editor.wordWrap": "off",
    "redhat.telemetry.enabled": true,
    "editor.detectIndentation": false,
    "notebook.cellToolbarLocation": {
        "default": "right",
        "jupyter-notebook": "left"
    }
}
"editor.defaultFormatter": null
"editor.formatOnType": false
"editor.formatOnPaste": false
"editor.formatOnSaveMode": "file"
"editor.codeActionsOnSave": {}

Is there any documentation on viewing the generated .prof files, or does that require tools we don't have access to? I'd kinda like to be able to see what's actually in the data I'd be sending in case there's anything in there I wouldn't want to send, even PGP-encrypted.

@radeksimko
Copy link
Member

Is there any documentation on viewing the generated .prof files, or does that require tools we don't have access to? I'd kinda like to be able to see what's actually in the data I'd be sending in case there's anything in there I wouldn't want to send, even PGP-encrypted.

The best way to inspect the profile would be via go tool pprof, see https://pkg.go.dev/net/http/pprof for more.

@mattfrsn
Copy link

mattfrsn commented Dec 8, 2021

I'm having the same CPU issues on Mac Monterey v12.0.1. Adding "requiredVersion": "0.24.0" resolved it for me thanks @jpogran

@enricojonas
Copy link

Confirming the issue on Ubuntu 21.10, workaround works for me as well for now.

@radeksimko
Copy link
Member

I'm afraid that there's very little progress we can make in fixing the bug without a CPU profile from an affected user.

Could any of you obtain the CPU profile and upload it here or send it to my email address radek<at>hashicorp.com, please? https://github.com/hashicorp/terraform-ls/blob/main/docs/TROUBLESHOOTING.md#cpu-profiling

Thanks!

@ghost
Copy link

ghost commented Dec 15, 2021

@radeksimko I have the issue and I'm happy to send you a cpu profile - the only issue is that when I run the profiler command it starts a new terraform-ls process which is nice and idle while the terraform-ls process that VS Code uses is nice and busy. Is there a way to force VSCode to use the running t-ls process or ......

@radeksimko
Copy link
Member

@rupertohpen That is unfortunate indeed.

The language server does have a TCP option (see serve command flag -port), which would allow editors/clients to attach to a particular TCP port. However, we have not implemented the corresponding functionality on the VS Code extension side yet, so there's no way for the extension to connect to a TCP port.

This is of course a stretch but you could try to reproduce it in Sublime Text via the LSP plugin, which provides this option https://github.com/hashicorp/terraform-ls/blob/main/docs/USAGE.md#sublime-text-2

@tam116
Copy link

tam116 commented Dec 16, 2021

@rupertohpen Try adding this to your settings.json

"terraform.languageServer": {

        "requiredVersion": "0.25.0",
        "args" : ["serve", "-cpuprofile=/tmp/terraform-ls-cpu-{{timestamp}}.prof" ],
    },

@tam116
Copy link

tam116 commented Dec 16, 2021

@radeksimko I emailed a copy of both my memory and cpu profiles

@ghost

This comment has been minimized.

@radeksimko
Copy link
Member

We're still investigating why the CPU profile for some people on Windows doesn't get generated (#755 )

However 0.25.1 was just released and contains a change which reduces parallelism, which should flatten the CPU spikes folks have reported. Can you try the new version out and let me know if it's better?

In VS Code the extension checks for new LS version every 24 hours, or after VS Code starts.

It does mean that indexing of modules on the background will potentially take longer, meaning that cross-module references etc. may not appear for a while until they're indexed, but there should be less pressure on the CPU.

@fishfacemcgee
Copy link

fishfacemcgee commented Jan 6, 2022

With 0.25.1 I'm still seeing very high CPU usage when the on-save formatter runs and it still hangs for multiple seconds each time I save, whereas on <= 0.24 it's perceptually instant.

Screen Shot 2022-01-06 at 10 54 17 AM

@jpogran
Copy link
Contributor

jpogran commented Jan 6, 2022

@fishfacemcgee what terraform vs code extension version are you running and how are you opening your project? That looks to me like multiple terraform-ls processes. In 2.17.0 we finalized support for multiple folder workspaces, so there should be only one terraform-ls process per vscode editor window. Or, if you open several folders in a multi-folder workspace, there should be only one terraform-ls process running.

@fishfacemcgee
Copy link

@jpogran

VS Code: 1.63.2
Terraform Extension: 2.17.0
terraform-ls: 0.25.1
MacOS: 11.6 (20G165)
terraform: 1.0.10

The nature of my work has me jumping between multiple TF repos regularly, so I tend to have multiple VS Code windows running at a time. At the time of the screenshot, there were 4 VS Code windows open for TF workspaces, so it appears that it's one-to-one as expected. If I close the other windows, the only material change is the process count drops to one. CPU usage is still extremely high when the on save formatter runs, and the formatting still takes multiple seconds and/or hangs entirely until I cancel it via the VS Code notification (which still requires me to quit the terraform-ls process via Activity Monitor to keep my laptop from being a jet engine)

Screen Shot 2022-01-06 at 11 08 39 AM

@jpogran
Copy link
Contributor

jpogran commented Jan 6, 2022

@fishfacemcgee Thanks, that makes sense. Was trying to make sure it wasn't another reason.

@radeksimko
Copy link
Member

@fishfacemcgee I'm not entirely convinced this is the same problem, even if the symptoms (high CPU) looks the same.

Do you mind sharing the log from the Output pane, so we can see what's going on when the formatting is attempted? Ideally the whole log.
Screenshot 2022-01-06 at 16 28 44

You can also GPG-encrypt it if you're worried about sensitive data in it.

Secondly, given that you're on Unix-based OS - can you collect a CPU profile and share it with us? https://github.com/hashicorp/terraform-ls/blob/main/docs/TROUBLESHOOTING.md#cpu-profiling

@fishfacemcgee
Copy link

fishfacemcgee commented Jan 6, 2022

@radeksimko You'll be receiving an email with the output data in a bit. As far as the CPU profile, I tried configuring the language server as seen in the code block below and something isn't working correctly. The file gets created, but then nothing gets written to it. I tried a different directory in case there was something weird going on with permissions, and it made no difference.

    "terraform.languageServer": {
        "external": true,
        "args": [
            "serve",
            "-cpuprofile=/tmp/terraform-ls-cpu.prof"
        ]
    },

@radeksimko
Copy link
Member

@fishfacemcgee the CPU profile gets written upon shutdown of the process (which can be triggered by shutdown of VS Code), but it has to be graceful shutdown (i.e. SIGTERM or SIGINT in signal speak).

Based on the data so far reviewed I'm also proposing disabling the reference count code lens by default (currently enabled by default in the VS Code extension).
In the meantime, can you try disabling it using the following settings yourself:

"terraform.codelens.referenceCount": false,

and see if that makes an impact on the CPU usage?

@jpogran
Copy link
Contributor

jpogran commented Jan 10, 2022

All,

We recently released v2.18.0 of the extension (using terraform-ls 0.25.1), which changes terraform.codelens.referenceCount to be disabled by default. In certain scenarios the overhead of pre-calculating the number of references for each block in a document causes high CPU utilization. If you could update to the latest version and verify, we would sincerely appreciate it.

@radeksimko
Copy link
Member

We have also just released language server 0.25.2 which patches a number of bugs, further reducing overhead (which could result higher CPU usage) in various scenarios, such as publishing diagnostics, refreshing code lens or telemetry.

With that in mind, I believe we have done all we could based on the data and knowledge available at this point, so I'm going to close this issue.

If someone still experiences high CPU usage after upgrading to the latest 2.18.0+ of the extension and 0.25.2 of LS, I would encourage you to file a new issue and attach details, such as log file, CPU profile and situation in which this occurs.

Thank you all!

@github-actions
Copy link

I'm going to lock this issue because it has been closed for 30 days ⏳. This helps our maintainers find and focus on the active issues.
If you have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Feb 11, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Something isn't working waiting-response
Projects
None yet
Development

No branches or pull requests