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

x/tools/gopls: extreme slowdown when using VSCode Go + gopls #43127

Closed
jeremywiebe opened this issue Dec 10, 2020 · 7 comments
Closed

x/tools/gopls: extreme slowdown when using VSCode Go + gopls #43127

jeremywiebe opened this issue Dec 10, 2020 · 7 comments
Labels
FrozenDueToAge gopls Issues related to the Go language server, gopls. Tools This label describes issues relating to any tools in the x/tools repository. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.

Comments

@jeremywiebe
Copy link

Please review the documentation before filing an issue.
Helpful pages include:

Please answer these questions before submitting your issue. Thanks!

What version of Go, VS Code & VS Code Go extension are you using?

  • Run go version to get version of Go
    • go version go1.14.13 darwin/amd64
  • Run gopls -v version to get version of Gopls if you are using the language server.
    • golang.org/x/tools/gopls v0.5.5
      • golang.org/x/tools/gopls@v0.5.5 h1:YBLs2WCwxx6mBF98Y6/mDIpKhP4Dt4Dz2q6LnMRBpDw=
  • Run code -v or code-insiders -v to get version of VS Code or VS Code Insiders
    • 1.51.1
    • e5a624b788d92b8d34d1392e4c4d9789406efe8f
    • x64
  • Check your installed extensions to get the version of the VS Code Go extension
    • v0.19.0
  • Run go env to get the go development environment details
     GO111MODULE=""
     GOARCH="amd64"
     GOBIN=""
     GOCACHE="/Users/jeremy/Library/Caches/go-build"
     GOENV="/Users/jeremy/Library/Application Support/go/env"
     GOEXE=""
     GOFLAGS=""
     GOHOSTARCH="amd64"
     GOHOSTOS="darwin"
     GOINSECURE=""
     GONOPROXY=""
     GONOSUMDB=""
     GOOS="darwin"
     GOPATH="/Users/jeremy/go"
     GOPRIVATE=""
     GOPROXY="https://proxy.golang.org,direct"
     GOROOT="/usr/local/Cellar/go@1.14/1.14.13/libexec"
     GOSUMDB="sum.golang.org"
     GOTMPDIR=""
     GOTOOLDIR="/usr/local/Cellar/go@1.14/1.14.13/libexec/pkg/tool/darwin_amd64"
     GCCGO="gccgo"
     AR="ar"
     CC="clang"
     CXX="clang++"
     CGO_ENABLED="1"
     GOMOD="/Users/jeremy/khan/webapp/go.mod"
     CGO_CFLAGS="-g -O2"
     CGO_CPPFLAGS=""
     CGO_CXXFLAGS="-g -O2"
     CGO_FFLAGS="-g -O2"
     CGO_LDFLAGS="-g -O2"
     PKG_CONFIG="pkg-config"
     GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/pn/4g431jtn53lchsdkgl46_5g80000gn/T/go-build788658611=/tmp/go-build -gno-record-gcc-switches -fno-common"
    

Share the Go related settings you have added/edited

    "go.autocompleteUnimportedPackages": true,
    "go.useLanguageServer": true,
    "go.languageServerFlags": [
        "-logfile", "/Users/jeremy/Desktop/gopls.log",
        "-rpc.trace"
    ],
    "go.formatTool": "goimports",
    "go.lintTool": "golangci-lint",
    "go.lintFlags": [
        "--fast",
        "--fix"
    ],

    "gopls": {
        "verboseOutput": true
    },

Describe the bug

Lately, when working in our Go repo with VSCode, it is responsive for the first while (minutes) but after I've worked a bit and done a few saves, CPU load really spikes. I haven't completely nailed down why, but I suspect that it partly due to gopls invoking go list which forks out to git. Quite often my Activity Monitor lists 2 git processes using quite a but of CPU time.

I've captured pstree output for the VSCode process showing the two go list and git sub-processes. These git processes last quite a while and appear to block file saves from completing (for example, as I write this bug, VSCode has been trying to save a .go file for at least a minute).

Once this go list/git process happens, it seems like it enters a loop and never completes. go list and git just keep getting run long after I VSCode has been inactive (although the "Saving..." message is still visible in the bottom right (see Screenshots section).

pstree output

-+= 00001 root /sbin/launchd
 \-+= 07691 jeremy /Applications/Visual Studio Code.app/Contents/MacOS/Electron
   |--- 07694 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (GPU).app/Contents/MacOS/Code Helper (GPU) --type=gpu-process --field-trial-handle=1718379636,17854429940943985964,4355844198089574154,131072 --enable-features=WebComponentsV0Enabled --disable-features=SpareRendererForSitePerProcess --disable-color-correct-rendering --gpu-preferences=MAAAAAAAAAAgAAAAAAAAAAAAAAAAAAAAAABgAAAAAAAQAAAAAAAAAAAAAAAAAAAACAEAACAAAAAAAQAAAAAAAAgBAAAAAAAAEAEAAAAAAAAYAQAAAAAAACABAAAAAAAAKAEAAAAAAAAwAQAAAAAAADgBAAAAAAAAQAEAAAAAAABIAQAAAAAAAFABAAAAAAAAWAEAAAAAAABgAQAAAAAAAGgBAAAAAAAAcAEAAAAAAAB4AQAAAAAAAIABAAAAAAAAiAEAAAAAAACQAQAAAAAAAJgBAAAAAAAAoAEAAAAAAACoAQAAAAAAALABAAAAAAAAuAEAAAAAAADAAQAAAAAAAMgBAAAAAAAA0AEAAAAAAADYAQAAAAAAAOABAAAAAAAA6AEAAAAAAADwAQAAAAAAAPgBAAAAAAAAEAAAAAAAAAAAAAAAAAAAABAAAAAAAAAAAAAAAAIAAAAQAAAAAAAAAAAAAAAGAAAAEAAAAAAAAAAAAAAABwAAABAAAAAAAAAAAAAAAAgAAAAQAAAAAAAAAAAAAAAKAAAAEAAAAAAAAAAAAAAACwAAABAAAAAAAAAAAAAAAA0AAAAQAAAAAAAAAAEAAAAAAAAAEAAAAAAAAAABAAAAAgAAABAAAAAAAAAAAQAAAAYAAAAQAAAAAAAAAAEAAAAHAAAAEAAAAAAAAAABAAAACAAAABAAAAAAAAAAAQAAAAoAAAAQAAAAAAAAAAEAAAALAAAAEAAAAAAAAAABAAAADQAAABAAAAAAAAAABAAAAAAAAAAQAAAAAAAAAAQAAAACAAAAEAAAAAAAAAAEAAAABgAAABAAAAAAAAAABAAAAAcAAAAQAAAAAAAAAAQAAAAIAAAAEAAAAAAAAAAEAAAACgAAABAAAAAAAAAABAAAAAsAAAAQAAAAAAAAAAQAAAANAAAAEAAAAAAAAAAGAAAAAAAAABAAAAAAAAAABgAAAAIAAAAQAAAAAAAAAAYAAAAGAAAAEAAAAAAAAAAGAAAABwAAABAAAAAAAAAABgAAAAgAAAAQAAAAAAAAAAYAAAAKAAAAEAAAAAAAAAAGAAAACwAAABAAAAAAAAAABgAAAA0AAAA= --shared-files
   |--- 07696 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper.app/Contents/MacOS/Code Helper --type=utility --field-trial-handle=1718379636,17854429940943985964,4355844198089574154,131072 --enable-features=WebComponentsV0Enabled --disable-features=SpareRendererForSitePerProcess --lang=en-US --service-sandbox-type=network --standard-schemes=vscode-webview,vscode-webview-resource --secure-schemes=vscode-webview,vscode-webview-resource --bypasscsp-schemes --cors-schemes=vscode-webview,vscode-webview-resource --fetch-schemes=vscode-webview,vscode-webview-resource --service-worker-schemes --shared-files --seatbelt-client=48
   |-+- 07698 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) --type=renderer --disable-color-correct-rendering --field-trial-handle=1718379636,17854429940943985964,4355844198089574154,131072 --enable-features=WebComponentsV0Enabled --disable-features=SpareRendererForSitePerProcess --lang=en-US --standard-schemes=vscode-webview,vscode-webview-resource --secure-schemes=vscode-webview,vscode-webview-resource --bypasscsp-schemes --cors-schemes=vscode-webview,vscode-webview-resource --fetch-schemes=vscode-webview,vscode-webview-resource --service-worker-schemes --app-path=/Applications/Visual Studio Code.app/Contents/Resources/app --node-integration --webview-tag --no-sandbox --no-zygote --native-window-open --preload=/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/base/parts/sandbox/electron-browser/preload.js --background-color=#ffffff --num-raster-threads=4 --enable-zero-copy --enable-gpu-memory-buffer-compositor-resources --enable-main-frame-before-activation --renderer-client-id=5 --no-v8-untrusted-code-mitigations --shared-files
   | \-+- 07712 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) --inspect-port=0 /Applications/Visual Studio Code.app/Contents/Resources/app/out/bootstrap-fork --type=extensionHost
   |   |--- 07722 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) /Users/jeremy/.vscode/extensions/dbaeumer.vscode-eslint-2.1.13/server/out/eslintServer.js --node-ipc --clientProcessId=7712
   |   \--- 69158 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) /Applications/Visual Studio Code.app/Contents/Resources/app/extensions/json-language-features/server/dist/node/jsonServerMain --node-ipc --clientProcessId=7712
   |--- 07716 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) --type=renderer --disable-color-correct-rendering --field-trial-handle=1718379636,17854429940943985964,4355844198089574154,131072 --enable-features=WebComponentsV0Enabled --disable-features=SpareRendererForSitePerProcess --lang=en-US --standard-schemes=vscode-webview,vscode-webview-resource --secure-schemes=vscode-webview,vscode-webview-resource --bypasscsp-schemes --cors-schemes=vscode-webview,vscode-webview-resource --fetch-schemes=vscode-webview,vscode-webview-resource --service-worker-schemes --app-path=/Applications/Visual Studio Code.app/Contents/Resources/app --node-integration --no-sandbox --no-zygote --native-window-open --preload=/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/base/parts/sandbox/electron-browser/preload.js --background-color=#ffffff --disable-blink-features=Auxclick --num-raster-threads=4 --enable-zero-copy --enable-gpu-memory-buffer-compositor-resources --enable-main-frame-before-activation --renderer-client-id=7 --no-v8-untrusted-code-mitigations --shared-files
   |-+- 12334 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) --type=renderer --disable-color-correct-rendering --field-trial-handle=1718379636,17854429940943985964,4355844198089574154,131072 --enable-features=WebComponentsV0Enabled --disable-features=SpareRendererForSitePerProcess --lang=en-US --standard-schemes=vscode-webview,vscode-webview-resource --secure-schemes=vscode-webview,vscode-webview-resource --bypasscsp-schemes --cors-schemes=vscode-webview,vscode-webview-resource --fetch-schemes=vscode-webview,vscode-webview-resource --service-worker-schemes --app-path=/Applications/Visual Studio Code.app/Contents/Resources/app --node-integration --webview-tag --no-sandbox --no-zygote --native-window-open --preload=/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/base/parts/sandbox/electron-browser/preload.js --background-color=#ffffff --num-raster-threads=4 --enable-zero-copy --enable-gpu-memory-buffer-compositor-resources --enable-main-frame-before-activation --renderer-client-id=21 --no-v8-untrusted-code-mitigations --shared-files
   | |-+- 12335 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) --inspect-port=0 /Applications/Visual Studio Code.app/Contents/Resources/app/out/bootstrap-fork --type=extensionHost
   | | |--- 12356 jeremy /Users/jeremy/go/bin/gopls -mode=stdio -logfile /Users/jeremy/Desktop/gopls.log -rpc.trace
   | | \--- 12406 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) /Users/jeremy/.vscode/extensions/dbaeumer.vscode-eslint-2.1.13/server/out/eslintServer.js --node-ipc --clientProcessId=12335
   | |--- 12336 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) /Applications/Visual Studio Code.app/Contents/Resources/app/out/bootstrap-fork --type=watcherService
   | \--- 12338 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) /Applications/Visual Studio Code.app/Contents/Resources/app/out/bootstrap-fork --type=searchService
   \-+- 35952 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) --type=renderer --disable-color-correct-rendering --field-trial-handle=1718379636,17854429940943985964,4355844198089574154,131072 --enable-features=WebComponentsV0Enabled --disable-features=SpareRendererForSitePerProcess --lang=en-US --standard-schemes=vscode-webview,vscode-webview-resource --secure-schemes=vscode-webview,vscode-webview-resource --bypasscsp-schemes --cors-schemes=vscode-webview,vscode-webview-resource --fetch-schemes=vscode-webview,vscode-webview-resource --service-worker-schemes --app-path=/Applications/Visual Studio Code.app/Contents/Resources/app --node-integration --webview-tag --no-sandbox --no-zygote --native-window-open --preload=/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/base/parts/sandbox/electron-browser/preload.js --background-color=#ffffff --num-raster-threads=4 --enable-zero-copy --enable-gpu-memory-buffer-compositor-resources --enable-main-frame-before-activation --renderer-client-id=15 --no-v8-untrusted-code-mitigations --shared-files
     |--- 08510 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) /Applications/Visual Studio Code.app/Contents/Resources/app/out/bootstrap-fork --type=searchService
     |-+- 35953 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) --inspect-port=0 /Applications/Visual Studio Code.app/Contents/Resources/app/out/bootstrap-fork --type=extensionHost
     | |--- 61434 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) /Users/jeremy/.vscode/extensions/ms-python.vscode-pylance-2020.12.0/dist/server.bundle.js --cancellationReceive=file:fb5e23998095b579d0b37206dab84890c8100b37c8 --node-ipc --clientProcessId=35953
     | |--- 63745 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) /Users/jeremy/.vscode/extensions/graphql.vscode-graphql-0.3.13/out/server/server.js --node-ipc --clientProcessId=35953
     | |--- 66556 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) /Applications/Visual Studio Code.app/Contents/Resources/app/extensions/json-language-features/server/dist/node/jsonServerMain --node-ipc --clientProcessId=35953
     | \-+- 72433 jeremy /Users/jeremy/go/bin/gopls -mode=stdio -logfile /Users/jeremy/Desktop/gopls.log -rpc.trace
     |   |-+- 12558 jeremy go list -modfile=/var/folders/pn/4g431jtn53lchsdkgl46_5g80000gn/T/go.6f94832d2b73f67695c51752506ec8150b2e7fbb949f3e0b0b2a9de4eccb3b64.586304832.mod -e -json -compiled=true -test=true -export=false -deps=true -find=false -- github.com/.... github.com/....
     |   | \--- 12816 jeremy /Applications/Xcode-12.app/Contents/Developer/usr/bin/git -c log.showsignature=false log -n1 --format=format:%H %ct %D f9db26f03b03 --
     |   \-+- 12559 jeremy go list -modfile=/var/folders/pn/4g431jtn53lchsdkgl46_5g80000gn/T/go.6f94832d2b73f67695c51752506ec8150b2e7fbb949f3e0b0b2a9de4eccb3b64.084523935.mod -e -json -compiled=true -test=true -export=false -deps=true -find=false -- github.com/.... github.com/....
     |     \--- 12815 jeremy /Applications/Xcode-12.app/Contents/Developer/usr/bin/git -c log.showsignature=false log -n1 --format=format:%H %ct %D f9db26f03b03 --
     \--- 35965 jeremy /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Renderer).app/Contents/MacOS/Code Helper (Renderer) /Applications/Visual Studio Code.app/Contents/Resources/app/out/bootstrap-fork --type=watcherService

Trace output

gopls logs a bunch of stuff, but I've included the parts of the trace that seem relevant. Happy to gather more if needed.

[Trace - 12:12:45.620 PM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2020/12/10 12:12:45 141.858022ms for GOROOT= GOPATH=/Users/jeremy/go GO111MODULE=off GOPROXY=https://proxy.golang.org,direct PWD=/Users/jeremy/... go list -e -f {{context.ReleaseTags}}\n"}


[Trace - 12:12:45.623 PM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2020/12/10 12:12:45 205.606034ms for GOROOT= GOPATH=/Users/jeremy/go GO111MODULE=off GOPROXY=https://proxy.golang.org,direct PWD=/Users/jeremy/... go list -e -f {{context.ReleaseTags}}\n"}


[Trace - 12:12:45.660 PM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2020/12/10 12:12:45 306.916406ms for GOROOT= GOPATH=/Users/jeremy/go GO111MODULE= GOPROXY=https://proxy.golang.org,direct PWD=/Users/jeremy/... go list -modfile=/var/folders/pn/4g431jtn53lchsdkgl46_5g80000gn/T/go.6f94832d2b73f67695c51752506ec8150b2e7fbb949f3e0b0b2a9de4eccb3b64.449530308.mod -f \"{{context.GOARCH}} {{context.Compiler}}\" -- unsafe\n"}


[Trace - 12:12:45.914 PM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2020/12/10 12:12:45 604.946016ms for GOROOT= GOPATH=/Users/jeremy/go GO111MODULE= GOPROXY=https://proxy.golang.org,direct PWD=/Users/jeremy/... go list -modfile=/var/folders/pn/4g431jtn53lchsdkgl46_5g80000gn/T/go.6f94832d2b73f67695c51752506ec8150b2e7fbb949f3e0b0b2a9de4eccb3b64.427387987.mod -f \"{{context.GOARCH}} {{context.Compiler}}\" -- unsafe\n"}


[Trace - 12:14:15.905 PM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2020/12/10 12:14:15 1m30.630573255s for GOROOT= GOPATH=/Users/jeremy/go GO111MODULE= GOPROXY=https://proxy.golang.org,direct PWD=/Users/jeremy/... go list -modfile=/var/folders/pn/4g431jtn53lchsdkgl46_5g80000gn/T/go.6f94832d2b73f67695c51752506ec8150b2e7fbb949f3e0b0b2a9de4eccb3b64.449530308.mod -e -json -compiled=true -test=true -export=false -deps=true -find=false -- ...files...  \n"}

Steps to reproduce the behavior:

  1. Open a Go project in a large git repo (ours has a .git dir that is 7.5 GB!). Note also that the entire repo is in a single Go module (we have one go.mod at the root of the monorepo).
  2. Ensure the language server option is enabled in VSCode settings
  3. Start working on a .go file (it doesn't seem to matter which/where), make some code changes, save, make more changes, save. After a while gopls starts invoking (I suspect on Save) go list -modfile... which in turn invokes git for-each-ref). This causes a downwards spiral of performance and slow saves.

Screenshots or recordings

It's really common for me to see this "Saving..." dialog when working with VSCode (and it blocks saving for seconds to minutes each time).

image

@zkmoney
Copy link

zkmoney commented Dec 10, 2020

This is a perfect write up of what is happening to me as well. The only differences/additions I may add are:

  • The repo/module I am working in is not large (it is a handful of go files)
  • I am developing locally with a replace in the go.mod that targets a local module

If I can be of any help providing my system information or with debugging anything, please let me know.

@hyangah
Copy link
Contributor

hyangah commented Dec 10, 2020

@jeremywiebe Thanks for the report. I will transfer this to the gopls issue tracker for further investigation by gopls devs.

@zkmoney It sounds like a different workload, so it's possible that the underlying issue is different while the symptom is similar. Can you please open a separate issue, with the gopls trace? https://github.com/golang/tools/blob/master/gopls/doc/troubleshooting.md#vs-code

@hyangah hyangah changed the title Extreme slowdown when using VSCode Go + gopls x/tools/gopls: extreme slowdown when using VSCode Go + gopls Dec 10, 2020
@hyangah hyangah transferred this issue from golang/vscode-go Dec 10, 2020
@gopherbot gopherbot added Tools This label describes issues relating to any tools in the x/tools repository. gopls Issues related to the Go language server, gopls. labels Dec 10, 2020
@gopherbot gopherbot added this to the Unreleased milestone Dec 10, 2020
@heschi
Copy link
Contributor

heschi commented Dec 10, 2020

The go command should never invoke git on the current module -- it's aware of it only as a directory, not as a VCS repository. If you look at the working directory of the git command, you should find that it's running in the module cache somewhere.

Given the behavior you're seeing, the go command is trying to resolve an import that is not in any module currently required by the main module. It will use git to do that if the import path is excluded by GOPRIVATE/GONOPROXY, or if it's just not available from proxy.golang.org. The trigger is probably a change to an import statement, either manually or via an autocomplete, that causes it to search in some very large module. (That could even be an older/cached version of the main module, I'm not totally sure.)

If I'm right, some recent changes I made to gopls to avoid the network could be very helpful here. Could you try gopls at master? See https://github.com/golang/tools/blob/master/gopls/doc/user.md#unstable-versions.

@stamblerre stamblerre added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Dec 11, 2020
@denbeigh2000
Copy link

denbeigh2000 commented Dec 11, 2020

I've filed a new issue with this at #43181

Hello,

I experience similar issues to OP. I work in a large repo (hundreds of packages)
with a single go.mod at the top, and a number of replaced dependencies.

I observe a dialog box with Saving [file].go: Getting code actions from "Go",
usually after a few minutes of editing with several saves. Anecdotally, I see
these gradually increase as the editing session gets longer, and more saves are
performed.

My go env:

GO111MODULE="on"
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/ubuntu/.cache/go-build"
GOENV="/home/ubuntu/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/ubuntu/our_private_repository/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/ubuntu/our_private_repository/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/ubuntu/our_private_repository/opt/go1.15.5"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/ubuntu/our_private_repository/opt/go1.15.5/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/ubuntu/our_private_repository/go/src/our_module/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build155352447=/tmp/go-build -gno-record-gcc-switches"

My go-specific VSCode settings:

"go.useLanguageServer": true,
"gopls": {
  "local": "our_module",
  "staticcheck": false,
  // Prevent gopls from scanning parent and child directories for go.mod
  // files.
  "expandWorkspaceToModule": false,
  // Disable most codelens features by default for perf.
  "codelens": {
    "gc_details": false,
    "generate": false,
    "regenerate_cgo": true,
    "tidy": false,
    "upgrade_dependency": false,
    "vendor": false,
    "test": false,
  }
},
"go.languageServerExperimentalFeatures": {
  "experimentalWorkspaceModule": true,
  "diagnostics": true,
  "documentLink": false
},
"go.toolsGopath": "~/go",
"go.toolsEnvVars": {
  "GO111MODULE": "on"
},

"go.autocompleteUnimportedPackages": true,
"go.gocodeAutoBuild": false,
// Prefer streaming tests when running them interactively:
// https://golang.org/doc/go1.14#go-test
"go.testFlags": ["-v", "-race"],
"go.vetOnSave": "off",
"go.formatTool": "goimports",
"go.formatFlags": ["-local", "our_module"],
"go.lintTool": "golangci-lint",
"go.lintFlags": [
  "--enable",
  "govet",
  "--enable",
  "golint",
  "--enable",
  "errcheck",
  "--enable",
  "deadcode",
  "--enable",
  "varcheck"
],
"[go]": {
  "editor.formatOnSave": true,
  "editor.codeActionsOnSave": {
    "source.organizeImports": true
  }
},

"go.alternateTools": {
  "go": "${workspaceRoot}/../../../opt/goroot/bin/go"
},

My gopls version:

golang.org/x/tools/gopls v0.5.5
    golang.org/x/tools/gopls@v0.5.5 h1:YBLs2WCwxx6mBF98Y6/mDIpKhP4Dt4Dz2q6LnMRBpDw=

In my gopls trace, I see a number of cancelled RPC requests in a row, followed by a number of
operations returning:

Let me know if I can provide a more useful trace.

[Trace - 14:52:01.061 PM] Received response 'textDocument/foldingRange - (286)' in 28996ms.
Result: [{"startLine":2,"startCharacter":8,"endLine":17,"endCharacter":23,"kind":"imports"},{"startLine":20,"startCharacter":30,"endLine":26,"endCharacter":24},{"startLine":30,"startCharacter":190,"endLine":31,"endCharac
ter":68},{"startLine":35,"startCharacter":133,"endLine":38,"endCharacter":61},{"startLine":36,"startCharacter":68,"endLine":37,"endCharacter":69,"kind":"comment"},{"startLine":41,"startCharacter":69,"endLine":43,"endChar
acter":177,"kind":"comment"},{"startLine":44,"startCharacter":130,"endLine":47,"endCharacter":69},{"startLine":45,"startCharacter":68,"endLine":46,"endCharacter":69,"kind":"comment"},{"startLine":50,"startCharacter":191,
"endLine":77,"endCharacter":48},{"startLine":53,"startCharacter":16,"endLine":54,"endCharacter":75},{"startLine":60,"startCharacter":23,"endLine":61,"endCharacter":38},{"startLine":66,"startCharacter":42,"endLine":74,"en
dCharacter":2},{"startLine":66,"startCharacter":58,"endLine":73,"endCharacter":18},{"startLine":80,"startCharacter":185,"endLine":152,"endCharacter":20},{"startLine":81,"startCharacter":44,"endLine":139,"endCharacter":3}
,{"startLine":83,"startCharacter":30,"endLine":85,"endCharacter":20},{"startLine":87,"startCharacter":31,"endLine":89,"endCharacter":20},{"startLine":91,"startCharacter":31,"endLine":93,"endCharacter":20},{"startLine":96
,"startCharacter":31,"endLine":98,"endCharacter":20},{"startLine":107,"startCharacter":24,"endLine":123,"endCharacter":4},{"startLine":109,"startCharacter":19,"endLine":123,"endCharacter":3},{"startLine":113,"startCharac
ter":27,"endLine":121,"endCharacter":30},{"startLine":126,"startCharacter":18,"endLine":139,"endCharacter":2},{"startLine":130,"startCharacter":26,"endLine":137,"endCharacter":29},{"startLine":143,"startCharacter":16,"en
dLine":144,"endCharacter":53},{"startLine":148,"startCharacter":55,"endLine":149,"endCharacter":62}]

[Trace - 14:52:01.061 PM] Received response 'textDocument/codeLens - (287)' in 28943ms.
Result: null

[Trace - 14:52:01.061 PM] Received response 'textDocument/codeLens - (288)' in 28899ms.
Result: null

[Error - Received] 14:52:01.061 PM #289 JSON RPC cancelled

[Trace - 14:52:01.064 PM] Received response 'textDocument/codeAction - (290)' in 28543ms.
Result: null

[Error - Received] 14:52:01.065 PM #291 JSON RPC cancelled
[Error - Received] 14:52:01.065 PM #292 JSON RPC cancelled
[Error - Received] 14:52:01.065 PM #293 JSON RPC cancelled
[Error - Received] 14:52:01.065 PM #294 JSON RPC cancelled
[Error - Received] 14:52:01.065 PM #295 JSON RPC cancelled
[Error - Received] 14:52:01.065 PM #296 JSON RPC cancelled
[Error - Received] 14:52:01.065 PM #297 JSON RPC cancelled


[Trace - 14:52:01.065 PM] Received response 'textDocument/documentHighlight - (298)' in 25249ms.
Result: []

[Trace - 14:52:01.066 PM] Received response 'textDocument/codeAction - (299)' in 24999ms.
Result: null

[Trace - 14:52:01.067 PM] Received response 'textDocument/documentSymbol - (300)' in 24618ms.
Result: [{"name": ...]

When I switch to using gopls@master, I see some improvement.
Fewer RPC calls are cancelled, and response time has decreased.

All settings and configuration are unchanged, other than using gopls@master

New gopls version information:

golang.org/x/tools/gopls master
    golang.org/x/tools/gopls@v0.0.0-20201211185031-d93e913c1a58 h1:VxtAq4uV1lJkZzfzd7XQnTy2oqRHDJdCDlDAGlCjJgs=

Trace output:

[Trace - 14:23:27.442 PM] Received response 'textDocument/foldingRange - (244)' in 14ms.
Result: [{"startLine":2,"startCharacter":8,"endLine":17,"endCharacter":23,"kind":"imports"},{"startLine":20,"startCharacter":30,"endLine":26,"endCharacter":24},{"startLine":30,"startCharacter":190,"endLine":31,"endCharacter":68},{"startLine":35,"startCharacter":133,"endLine":38,"endCharacter":61},{"startLine":36,"startCharacter":68,"endLine":37,"endCharacter":69,"kind":"comment"},{"startLine":41,"startCharacter":69,"endLine":43,"endCharacter":177,"kind":"comment"},{"startLine":44,"startCharacter":130,"endLine":47,"endCharacter":69},{"startLine":45,"startCharacter":68,"endLine":46,"endCharacter":69,"kind":"comment"},{"startLine":50,"startCharacter":191,"endLine":77,"endCharacter":48},{"startLine":53,"startCharacter":16,"endLine":54,"endCharacter":75},{"startLine":60,"startCharacter":23,"endLine":61,"endCharacter":38},{"startLine":66,"startCharacter":42,"endLine":74,"endCharacter":2},{"startLine":66,"startCharacter":58,"endLine":73,"endCharacter":18},{"startLine":80,"startCharacter":185,"endLine":140,"endCharacter":20},{"startLine":81,"startCharacter":44,"endLine":127,"endCharacter":3},{"startLine":83,"startCharacter":30,"endLine":85,"endCharacter":20},{"startLine":89,"startCharacter":23,"endLine":91,"endCharacter":14},{"startLine":95,"startCharacter":24,"endLine":111,"endCharacter":4},{"startLine":97,"startCharacter":19,"endLine":111,"endCharacter":3},{"startLine":101,"startCharacter":27,"endLine":109,"endCharacter":30},{"startLine":114,"startCharacter":18,"endLine":127,"endCharacter":2},{"startLine":118,"startCharacter":26,"endLine":125,"endCharacter":29},{"startLine":131,"startCharacter":16,"endLine":132,"endCharacter":53},{"startLine":136,"startCharacter":55,"endLine":137,"endCharacter":62}]

[Trace - 14:23:27.476 PM] Sending request 'textDocument/codeLens - (245)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/..."}}

[Trace - 14:23:27.476 PM] Sending request 'textDocument/codeAction - (246)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/..."},"range":{"start":{"line":91,"character":14},"end":{"line":91,"character":14}},"context":{"diagnostics":[]}}

[Trace - 14:23:27.476 PM] Received response 'textDocument/codeLens - (245)' in 0ms.
Result: null

[Trace - 14:23:27.477 PM] Received response 'textDocument/codeAction - (246)' in 1ms.
Result: null

[Trace - 14:23:27.554 PM] Sending request 'textDocument/documentHighlight - (247)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/..."},"position":{"line":91,"character":13}}

[Trace - 14:23:27.555 PM] Received response 'textDocument/documentHighlight - (247)' in 0ms.
Result: []

[Trace - 14:23:27.630 PM] Received notification 'textDocument/publishDiagnostics'.
Params: {"uri":"file:///home/ubuntu/...","version":91,"diagnostics":[{"range":{"start":{"line":89,"character":2},"end":{"line":89,"character":3}},"severity":1,"source":"compiler","message":"x declared but not used"}]}

[Trace - 14:23:27.661 PM] Sending request 'textDocument/codeLens - (248)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/..."}}

[Trace - 14:23:27.661 PM] Received response 'textDocument/codeLens - (248)' in 0ms.
Result: null

[Trace - 14:23:28.019 PM] Sending request 'textDocument/codeAction - (249)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/...},"range":{"start":{"line":91,"character":13},"end":{"line":91,"character":13}},"context":{"diagnostics":[]}}

[Trace - 14:23:28.019 PM] Received response 'textDocument/codeAction - (249)' in 0ms.
Result: null

[Trace - 14:23:48.355 PM] Sending request 'textDocument/documentSymbol - (250)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/..."}}

@stamblerre
Copy link
Contributor

@denbeigh2000: Do you mind opening a separate issue and including the output of running gopls -rpc.trace -v check path/to/file.go in your workspace root? It will be easy to investigate separately since the issues are not necessarily related.

@jeremywiebe
Copy link
Author

Thanks for the explanation @hyangah. I tried gopls@master and it seems to improve the situation considerably. I'll keep an eye on things and if I notice it spiralling again, I can log a new bug (or re-open this one, whichever the golang team prefers). Thank-you.

@stamblerre stamblerre added this to Needs Triage in vscode-go: gopls by default via automation Dec 16, 2020
@stamblerre stamblerre moved this from Needs Triage to Waiting for Info in vscode-go: gopls by default Dec 16, 2020
@hyangah
Copy link
Contributor

hyangah commented Dec 18, 2020

@jeremywiebe Thank you for updating the status! The new version of gopls with the fixes that was master was released this week. Please update to the stable version (v0.6.1), and file a new issue if you observe issues (feel free to link this issue as a reference if you believe the symptom is similar). Thanks!

@hyangah hyangah closed this as completed Dec 18, 2020
vscode-go: gopls by default automation moved this from Waiting for Info to Done Dec 18, 2020
@stamblerre stamblerre removed this from the gopls/vscode-go milestone Dec 18, 2020
@golang golang locked and limited conversation to collaborators Dec 18, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge gopls Issues related to the Go language server, gopls. Tools This label describes issues relating to any tools in the x/tools repository. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
No open projects
Development

No branches or pull requests

7 participants