Terrible format-on-save performance

[adamrothman]

Extension Version

v2.29.0

VS Code Version

Version: 1.84.2 (Universal)
Commit: 1a5daa3a0231a0fbba4f14db7ec463cf99d7768e
Date: 2023-11-09T10:52:33.687Z
Electron: 25.9.2
ElectronBuildId: 24603566
Chromium: 114.0.5735.289
Node.js: 18.15.0
V8: 11.4.183.29-electron.0
OS: Darwin x64 23.1.0

Operating System

macOS Sonoma 14.1.1 (23B81)

Terraform Version

Terraform v1.5.7 on darwin_amd64

Behavior

Saving even a single-line change to a Terraform file causes the extension to hang for 30s to a minute or even longer.

Opening the VSCode console to Output > HashiCorp Terraform while this is happening shows thousands of lines like this flying by:

2023/11/17 09:03:35 jobs.go:461: JOBS: Finishing job "14867": "OpTypePreloadEmbeddedSchema" for {"file:///REDACTED/terraform/modules/vault/modules/basic"} (err = file:///REDACTED/terraform/modules/vault/modules/basic: state not changed, deferredJobs: [])
2023/11/17 09:03:35 jobs.go:321: JOBS: Dispatching next job "14868" (scheduler prio: -1, job prio: 0, isDirOpen: false): "OpTypeDecodeReferenceTargets" for {"file:///REDACTED/terraform/modules/vault/modules/basic"}
2023/11/17 09:03:35 jobs.go:461: JOBS: Finishing job "14868": "OpTypeDecodeReferenceTargets" for {"file:///REDACTED/terraform/modules/vault/modules/basic"} (err = file:///REDACTED/terraform/modules/vault/modules/basic: state not changed, deferredJobs: [])
2023/11/17 09:03:35 jobs.go:321: JOBS: Dispatching next job "14869" (scheduler prio: -1, job prio: 0, isDirOpen: false): "OpTypeDecodeReferenceOrigins" for {"file:///REDACTED/terraform/modules/vault/modules/basic"}
2023/11/17 09:03:35 jobs.go:461: JOBS: Finishing job "14869": "OpTypeDecodeReferenceOrigins" for {"file:///REDACTED/terraform/modules/vault/modules/basic"} (err = file:///REDACTED/terraform/modules/vault/modules/basic: state not changed, deferredJobs: [])
2023/11/17 09:03:35 jobs.go:321: JOBS: Dispatching next job "14870" (scheduler prio: -1, job prio: 0, isDirOpen: false): "OpTypeParseVariables" for {"file:///REDACTED/terraform/modules/vault/modules/basic"}
2023/11/17 09:03:35 jobs.go:461: JOBS: Finishing job "14870": "OpTypeParseVariables" for {"file:///REDACTED/terraform/modules/vault/modules/basic"} (err = file:///REDACTED/terraform/modules/vault/modules/basic: state not changed, deferredJobs: [])
2023/11/17 09:03:35 jobs.go:321: JOBS: Dispatching next job "14871" (scheduler prio: -1, job prio: 0, isDirOpen: false): "OpTypeDecodeVarsReferences" for {"file:///REDACTED/terraform/modules/vault/modules/basic"}
2023/11/17 09:03:35 jobs.go:461: JOBS: Finishing job "14871": "OpTypeDecodeVarsReferences" for {"file:///REDACTED/terraform/modules/vault/modules/basic"} (err = file:///REDACTED/terraform/modules/vault/modules/basic: state not changed, deferredJobs: [])
2023/11/17 09:03:35 jobs.go:321: JOBS: Dispatching next job "14872" (scheduler prio: -1, job prio: 0, isDirOpen: false): "OpTypeParseModuleConfiguration" for {"file:///REDACTED/terraform/modules/vault/modules/basic"}

I'm no expert, but it seems like the plugin is doing a ton of unnecessary work every time I save. I understand there's a lot of bookkeeping that needs to happen behind the scenes, but this feels like a scheduling problem to me. Formatting a file does not depend on any internal state – running terraform fmt whatever.tf executes in milliseconds – so I'm not sure why the plugin needs to block formatting on whatever else it's doing.

Steps to Reproduce

1. Open a TF file
2. Change a single line of that file
3. Save the file
4. Watch gray hairs appear before your eyes while you wait for format-on-save to complete

Terraform Configuration

No response

Project Structure

I'm working in a very large project with thousands of individual .tf files spread across many distinct environments and modules. This happens in TF environments across the project and is not specific to a single one.

In the instance that frustrated me enough to file this issue, I'm working in a module that itself contains many instantiations of a different, smaller module.

Gist

No response

Anything Else?

Relevant VSCode settings:

    "[terraform]": {
        "editor.defaultFormatter": "hashicorp.terraform",
        "editor.formatOnSave": true,
        "editor.formatOnSaveMode": "file",
        "editor.tabSize": 2
    },
    "[terraform-vars]": {
        "editor.defaultFormatter": "hashicorp.terraform",
        "editor.formatOnSave": true,
        "editor.formatOnSaveMode": "file",
        "editor.tabSize": 2
    },

References

No response

Community Note

• Please vote on this issue by adding a 👍 reaction to the original issue to help the community and maintainers prioritize this request
• Please do not leave "+1" or other comments that do not add relevant new information or questions, they generate extra noise for issue followers and do not help prioritize the request
• If you are interested in working on this issue or have submitted a pull request, please leave a comment

[jpogran]

Thanks for raising an issue @adamrothman, we appreciate receiving detailed reports like these.

I'm working in a very large project with thousands of individual .tf files spread across many distinct environments and modules. This happens in TF environments across the project and is not specific to a single one.

We have a pinned issue tracking our investigations and continuing work on different performance issues in #1557. I need to update it as we are aware of situations like yours where you open a folder with a very large set of Terraform modules and files. As we write in that issue, we do a lot of work in the background to understand the code you're working on, for more than just the open file. We have an indexing process that finds all the Terraform files and modules in your current working directory and builds an understanding of all them.

The short of this if you open a directory with many hundreds of folders and files, this may trigger more processing jobs than we intend, and in this case we're processing those folders and files before your format command runs.

We did some work in the past to prevent extra processing jobs in the most recent releases, which leads me to thinking you may not be on the latest terraform-ls version. It is possible to set terraform.languageServer.path to a custom terraform-ls binary, and not the one shipped with the extension. While I see in your post that you're running 2.29.0, which is the latest extension version, I just want to be sure you're using the shipped terraform-ls and not from somewhere else. You can check by opening the 'HashiCorp Terraform' output pane and looking at the first line:

I'm working in a module that itself contains many instantiations of a different, smaller module.

While you may not be working directly with symlinks, this does sound similar to our investigation for hashicorp/terraform-ls#1409. Since we process all the files and modules in the opened folder, we will build references for each of those "many instantiations of a...smaller module". This can be added more processing jobs than necessary, which exacerbates your problem. I don't have a solution for you right now, but we are working on it.

[adamrothman]

Thank you very much James, I really appreciate the detailed reply. It looks like I am using the terraform-ls that ships with the extension:

Launching language server: /Users/adam.rothman/.vscode/extensions/hashicorp.terraform-2.29.0-darwin-x64/bin/terraform-ls serve
Client: Stopped --> Starting

Please let me know if there's any additional information I can provide to help with your work.

[andrewfraley]

I'm having the same issue with a large project that has about 140 TF files in the same directory, it's pretty much unusable with formatOnSave: true. I previously solved similar issues by setting the following, but the -tf-exec flag isn't supported anymore.

"terraform.languageServer": {
  "args": [
    "serve",
    "-tf-exec=/usr/local/bin/terraform"
  ]
}

Please let me know if there's anything I can assist with as far as troubleshooting goes.

[jpogran]

Hey @andrewfraley, the best thing you can do to help us is open a new issue so we can get the version, environment, and other questions answered for your specific situation. This helps us collate information and see patterns and ask questions specific to your use case. For example, I would like to discuss your settings but I also don't want to divert the focus here.

[github-actions]

Marking this issue as stale due to inactivity over the last 30 days. This helps our maintainers find and focus on the active issues. If this issue receives no comments in the next 30 days it will automatically be closed. Maintainers can also remove the stale label.

Thank you for understanding.

[adamrothman]

Still an issue as far as I know.

[migueleliasweb]

Confirmed this still happens on v2.29.4.

Version: 1.86.2
Commit: 903b1e9d8990623e3d7da1df3d33db3e42d80eda
Date: 2024-02-13T19:41:37.860Z
Electron: 27.2.3
ElectronBuildId: 26908389
Chromium: 118.0.5993.159
Node.js: 18.17.1
V8: 11.8.172.18-electron.0
OS: Linux x64 6.2.0-39-generic

# relevant config
"[terraform]": {
      "editor.defaultFormatter": "hashicorp.terraform",
      "editor.formatOnSave": true,
      "editor.formatOnSaveMode": "file",
      "editor.formatOnType": false
}

---

I've debugged this a bit further. I think I could have an idea what is going on.

From the original post:

Opening the VSCode console to Output > HashiCorp Terraform while this is happening shows thousands of lines like this flying by

This also happens to be. Basically the same.

I noticed the extension appears to ignore the config "editor.formatOnType": false and for every keystroke it was "adding requests to its queue. When I finally saved a file, it would just add yet another extra request to the queue but at the time this happened, the queue was already way too long.

Edit: And the language server resource utilisation looks like this:

Also I noticed every time, for every key stroke it would run this kind of validation a few tens of times per keystroke:

2024/02/22 22:52:23 provider_schema.go:306: PSS: getting provider schema (<redacted>, registry.terraform.io/hashicorp/aws, ~> 5.20)
2024/02/22 22:52:23 provider_schema.go:306: PSS: getting provider schema (<redacted>, registry.terraform.io/hashicorp/http, ~> 2.1.0)
2024/02/22 22:52:23 provider_schema.go:306: PSS: getting provider schema (<redacted>, registry.terraform.io/-/terraform, )

It seems like the language server is reaching to the internet and fetching some kind of schema - probably to be able to validate the structure or something similar - instead of using some kind of cached version.

So, basically adding the two odd behaviours together, each .tf file save would take between 30s and 2min. It's getting real annoying.

For context I'm working on a medium sized project with a few thousands of line of terraform.

[dbanck]

Hi @migueleliasweb! Thanks for digging further!

Let me add some context to your findings:

• The LSP client sends every keystroke to the language server by default. This is done via the textDocument/didChange text synchronization method. The LS needs to know about every change to a file in order to keep an up-to-date representation of the file memory, so any other features like autocomplete or hover won't run on stale data.
• The above shouldn't trigger a formatting request (textDocument.formatting) or cause the file to be formatted. If you see something else, please let us know!
• I agree, the PSS: getting provider schema log messages are a bit annoying and confusing. The good news is that we're just accessing the schema in our internal memory and not doing anything expensive. I still think it's worth removing the message to reduce the noise and confusion. I've created Remove getting provider schema log line terraform-ls#1643 to address this.
• However, we're still doing too much work on a single keystroke, which allows a queue to build up and increase resource utilization too much.

It's an ongoing effort for us to improve this, and while we've shipped some meaningful improvements in the past, there's still a lot of work to be done, as this issue shows.

[migueleliasweb]

Hi @dbanck , thanks for answering so quickly!

The LSP client sends every keystroke to the language server by default. This is done via the textDocument/didChange text synchronization method. The LS needs to know about every change to a file in order to keep an up-to-date representation of the file memory, so any other features like autocomplete or hover won't run on stale data.

That's interesting! I didn't know each keystroke triggered events in the LSP. I wonder if the work for each keystroke could be consolidated in only invalidating the cache for the specific file and letting other triggers that are less frequent to take care of the heavy lifting such as formatting and autocompletion. Or maybe add some kind of lag check so the checks are only triggered at a maximum frequency instead of every keystroke.

The above shouldn't trigger a formatting request (textDocument.formatting) or cause the file to be formatted. If you see something else, please let us know!

I might try to peak into the vscode-terraform code to check this but I do think it was attempting to format the file or at least validate it in every keystroke.

I agree, the PSS: getting provider schema log messages are a bit annoying and confusing. The good news is that we're just accessing the schema in our internal memory and not doing anything expensive. I still think it's worth removing the message to reduce the noise and confusion. I've created hashicorp/terraform-ls#1643 to address this.

Awesome, thanks 👍 .

Ps: I initially thought the LSP was written in Go (given TF is also written in Go). It's actually written in typescript probably due to the integration method to VSCode itself 😐 .

[dbanck]

Ps: I initially thought the LSP was written in Go (given TF is also written in Go). It's actually written in typescript probably due to the integration method to VSCode itself 😐 .

The Terraform language server is written in Go (see https://github.com/hashicorp/terraform-ls/) and is a separate binary that can be used with any editor that has a language server client. This VS Code extension bundles the binary for an easy 1-click installation and adds some features on top.