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: notable slowdown on save with vscode-go + gopls #43181

Closed
denbeigh2000 opened this issue Dec 14, 2020 · 2 comments
Closed

x/tools/gopls: notable slowdown on save with vscode-go + gopls #43181

denbeigh2000 opened this issue Dec 14, 2020 · 2 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.
Milestone

Comments

@denbeigh2000
Copy link

This was created from a comment on #43127


I am experiencing an extended "Waiting for code actions from Go" after
saving when using vscode-go + gopls.

Notes:

  • We have a large number of packages in our module (thousands, including
    vendor/)
  • We have a large number of replace statements
  • We have a larger-than-normal git repository.

What did you do?

  • Open a Go file.
  • Allow the initial "loading packages" operation to finish.
  • Begin changing the file. Do not pause typing to wait for the autocomplete
    prompt.
  • Save the file one (or more) times, and continue working.

What did you expect to see?

  • I should be able to continue seeing prompts and suggestions in my editor.

What did you see instead?

  • I see a dialog box saying "Saving '[file name]': Getting code actions from
    "Go"", which persists for ~30-40 seconds during which I have no
    suggestions/langauge server features.

Build info

golang.org/x/tools/gopls v0.5.5
    golang.org/x/tools/gopls@v0.5.5 h1:YBLs2WCwxx6mBF98Y6/mDIpKhP4Dt4Dz2q6LnMRBpDw=
    github.com/BurntSushi/toml@v0.3.1 h1:WXkYYl6Yr3qBf1K79EBnL4mak0OimBfB0XUf9Vl28OQ=
    github.com/google/go-cmp@v0.5.1 h1:JFrFEBb2xKufg6XkJsJr+WbKb4FQlURi5RUcBveYu9k=
    github.com/sergi/go-diff@v1.1.0 h1:we8PVUC3FE2uYfodKH/nBHMSetSfHDR6scGdBi+erh0=
    golang.org/x/mod@v0.3.0 h1:RM4zey1++hCTbCVQfnWeKs9/IEsaBLA8vTkd0WVtmH4=
    golang.org/x/sync@v0.0.0-20201020160332-67f06af15bc9 h1:SQFwaSi55rU7vdNs9Yr0Z324VNlrF+0wMqRXT4St8ck=
    golang.org/x/tools@v0.0.0-20201204180437-c46b611624b3 h1:uxH+MECLNmX/vsPe4txyeQ1LCmhdUxf7p4hjkHexg+c=
    golang.org/x/xerrors@v0.0.0-20200804184101-5ec99f83aff1 h1:go1bK/D/BFZV2I8cIQd1NKEZ+0owSTG1fDTci4IqFcE=
    honnef.co/go/tools@v0.0.1-2020.1.6 h1:W18jzjh8mfPez+AwGLxmOImucz/IFjpNlrKVnaj2YVc=
    mvdan.cc/gofumpt@v0.0.0-20200927160801-5bfeb2e70dd6 h1:z+/YqapuV7VZPvBb3GYmuEJbA88M3PFUxaHilHYVCpQ=
    mvdan.cc/xurls/v2@v2.2.0 h1:NSZPykBXJFCetGZykLAxaL6SIpvbVy/UFEniIfHAa8A=

Relevant trace

[Trace - 11:45:02.826 AM] Sending request 'textDocument/foldingRange - (75)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/co/[redacted].go"}}



[Trace - 11:45:02.903 AM] Sending request 'textDocument/codeLens - (76)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/co/[redacted].go"}}


[Trace - 11:45:02.903 AM] Sending request 'textDocument/codeAction - (77)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/co/[redacted].go"},"range":{"start":{"line":154,"character":2},"end":{"line":154,"character":2}},"context":{"diagnostics":[]}}


[Trace - 11:45:02.984 AM] Sending request 'textDocument/codeLens - (78)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/co/[redacted].go"}}


[Trace - 11:45:03.345 AM] Sending request 'textDocument/codeAction - (79)'.
Result: (very large)


[Trace - 11:45:26.677 AM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2020/12/14 11:45:26 background imports cache refresh starting\n"}


[Info  - 11:45:26 AM] 2020/12/14 11:45:26 background imports cache refresh starting


[Trace - 11:45:26.732 AM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2020/12/14 11:45:26 background refresh finished after 55.87281ms\n"}


[Info  - 11:45:26 AM] 2020/12/14 11:45:26 background refresh finished after 55.87281ms

[Trace - 11:45:40.987 AM] Received response 'textDocument/foldingRange - (75)' in 38161ms.
Result: (very large)


[Trace - 11:45:40.988 AM] Received response 'textDocument/codeLens - (76)' in 38084ms.
Result: null


[Trace - 11:45:41.013 AM] Received response 'textDocument/codeAction - (77)' in 38109ms.
Result: null


[Trace - 11:45:41.013 AM] Received response 'textDocument/codeLens - (78)' in 38028ms.
Result: null


[Trace - 11:45:41.042 AM] Received response 'textDocument/codeAction - (79)' in 37696ms.
Result: null


[Trace - 11:45:41.077 AM] Received notification 'textDocument/publishDiagnostics'.
Params: {"uri":"file:///home/ubuntu/co/[redacted].go","diagnostics":[{"range":{"start":{"line":71,"character":4},"end":{"line":71,"character":43}},"severity":2,"source":"simplifycompositelit","message":"redundant type from array, slice, or map composite literal","tags":[1]}]}


[Trace - 11:45:41.081 AM] Received notification 'textDocument/publishDiagnostics'.
Params: {"uri":"file:///home/ubuntu/co/[redacted].go","diagnostics":[{"range":{"start":{"line":970,"character":5},"end":{"line":970,"character":42}},"severity":2,"source":"simplifycompositelit","message":"redundant type from array, slice, or map composite literal","tags":[1]},{"range":{"start":{"line":1917,"character":5},"end":{"line":1917,"character":42}},"severity":2,"source":"simplifycompositelit","message":"redundant type from array, slice, or map composite literal","tags":[1]}]}


[Trace - 11:45:41.084 AM] Received notification 'textDocument/publishDiagnostics'.
Params: {"uri":"file:///home/ubuntu/co/[redacted].go","version":63,"diagnostics":[]}

Per request, I ran gopls -v -rpc.trace check [file] on the file being edited
in the above trace

$ time ~/go/bin/gopls-v0.5.5 -v -rpc.trace check [redacted]
2020/12/14 11:58:09 Info:2020/12/14 11:58:09 go env for /home/ubuntu/co/backend/go/src/our_module
(root /home/ubuntu/co/backend/go/src/our_module)
(go version go version go1.15.5 linux/amd64)
(valid build configuration = true)
(build flags: [])
GOMODCACHE=/home/ubuntu/co/backend/go/pkg/mod
GOPATH=/home/ubuntu/co/backend/go
GOPROXY=https://proxy.golang.org,direct
GO111MODULE=on
GOMOD=/home/ubuntu/co/backend/go/src/our_module/go.mod
GOINSECURE=
GONOPROXY=
GOROOT=/home/ubuntu/co/backend/opt/go1.15.5
GOSUMDB=sum.golang.org
GONOSUMDB=
GOPRIVATE=
GOCACHE=/home/ubuntu/.cache/go-build
GOFLAGS=

2020/12/14 11:58:36 Info:2020/12/14 11:58:36 go/packages.Load
	snapshot=0
	directory=/home/ubuntu/co/backend/go/src/our_module
	query=[builtin our_module/...]
	packages=5729
~/go/bin/gopls-v0.5.5 -v -rpc.trace check   98.58s user 10.40s system 293% cpu 37.079 total

When using a recent checkout from master, I do not observe this issue.

Build info

golang.org/x/tools/gopls master
    golang.org/x/tools/gopls@v0.0.0-20201211185031-d93e913c1a58 h1:VxtAq4uV1lJkZzfzd7XQnTy2oqRHDJdCDlDAGlCjJgs=
    github.com/BurntSushi/toml@v0.3.1 h1:WXkYYl6Yr3qBf1K79EBnL4mak0OimBfB0XUf9Vl28OQ=
    github.com/google/go-cmp@v0.5.1 h1:JFrFEBb2xKufg6XkJsJr+WbKb4FQlURi5RUcBveYu9k=
    github.com/sergi/go-diff@v1.1.0 h1:we8PVUC3FE2uYfodKH/nBHMSetSfHDR6scGdBi+erh0=
    golang.org/x/mod@v0.3.0 h1:RM4zey1++hCTbCVQfnWeKs9/IEsaBLA8vTkd0WVtmH4=
    golang.org/x/sync@v0.0.0-20200625203802-6e8e738ad208 h1:qwRHBd0NqMbJxfbotnDhm2ByMI1Shq4Y6oRJo21SGJA=
    golang.org/x/tools@v0.0.0-20201021214918-23787c007979 h1:/zwc1T/TCf9evHOKBS+iOctX4P4oUufJApG6rD8Klos=
    golang.org/x/xerrors@v0.0.0-20200804184101-5ec99f83aff1 h1:go1bK/D/BFZV2I8cIQd1NKEZ+0owSTG1fDTci4IqFcE=
    honnef.co/go/tools@v0.0.1-2020.1.6 h1:W18jzjh8mfPez+AwGLxmOImucz/IFjpNlrKVnaj2YVc=
    mvdan.cc/gofumpt@v0.0.0-20200927160801-5bfeb2e70dd6 h1:z+/YqapuV7VZPvBb3GYmuEJbA88M3PFUxaHilHYVCpQ=
    mvdan.cc/xurls/v2@v2.2.0 h1:NSZPykBXJFCetGZykLAxaL6SIpvbVy/UFEniIfHAa8A=

Relevant trace

[Trace - 11:20:31.794 AM] Received response 'textDocument/documentHighlight - (20)' in 1520ms.
Result: [{"range":{"start":{"line":105,"character":32},"end":{"line":105,"character":44}},"kind":1},{"range":{"start":{"line":78,"character":16},"end":{"line":78,"character":28}},"kind":1},{"range":{"start":{"line":82,"character":27},"end":{"line":82,"character":39}},"kind":1},{"range":{"start":{"line":91,"character":1},"end":{"line":91,"character":13}},"kind":1},{"range":{"start":{"line":70,"character":16},"end":{"line":70,"character":28}},"kind":1},{"range":{"start":{"line":84,"character":1},"end":{"line":84,"character":13}},"kind":1},{"range":{"start":{"line":86,"character":32},"end":{"line":86,"character":44}},"kind":1},{"range":{"start":{"line":89,"character":27},"end":{"line":89,"character":39}},"kind":1},{"range":{"start":{"line":93,"character":32},"end":{"line":93,"character":44}},"kind":1},{"range":{"start":{"line":98,"character":27},"end":{"line":98,"character":39}},"kind":1},{"range":{"start":{"line":61,"character":1},"end":{"line":61,"character":13}},"kind":1},{"range":{"start":{"line":74,"character":16},"end":{"line":74,"character":28}},"kind":1},{"range":{"start":{"line":79,"character":7},"end":{"line":79,"character":19}},"kind":1},{"range":{"start":{"line":100,"character":1},"end":{"line":100,"character":13}},"kind":1},{"range":{"start":{"line":71,"character":7},"end":{"line":71,"character":19}},"kind":1},{"range":{"start":{"line":75,"character":7},"end":{"line":75,"character":19}},"kind":1}]


[Trace - 11:20:32.429 AM] Received response 'textDocument/codeAction - (21)' in 1905ms.
Result: null


[Trace - 11:20:32.430 AM] Received response 'textDocument/codeAction - (22)' in 1756ms.
Result: null


[Trace - 11:20:32.609 AM] Sending request 'textDocument/formatting - (23)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/co/[redacted].go"},"options":{"tabSize":4,"insertSpaces":false}}


[Trace - 11:20:32.616 AM] Received response 'textDocument/formatting - (23)' in 6ms.
Result: []


[Trace - 11:20:33.216 AM] Sending notification 'textDocument/didSave'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/co/[redacted].go","version":1}}


[Trace - 11:20:33.507 AM] Sending notification 'workspace/didChangeWatchedFiles'.
Params: {"changes":[{"uri":"file:///home/ubuntu/co/[redacted].go","type":2}]}


[Trace - 11:20:49.553 AM] Sending request 'textDocument/documentHighlight - (24)'.
Params: {"textDocument":{"uri":"file:///home/ubuntu/co/[redacted].go"},"position":{"line":78,"character":35}}
@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 14, 2020
@gopherbot gopherbot added this to the Unreleased milestone Dec 14, 2020
@stamblerre stamblerre changed the title x/tools/gopls: Notable slowdown on save with vscode-go + gopls x/tools/gopls: notable slowdown on save with vscode-go + gopls Dec 14, 2020
@stamblerre
Copy link
Contributor

You said that master seems to be working well--can you please try the current gopls pre-release? You can download it by running GO111MODULE=on go get golang.org/x/tools/gopls@v0.6.0-pre.1. We will be tagging this release on Wednesday, so if it works for you then it's possible the issue has already been resolved.

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

Hi,

I tested with the following version:

golang.org/x/tools/gopls v0.6.0
    golang.org/x/tools/gopls@v0.6.0-pre.1 h1:i+eJsCS+4N+3YSxLbuq0SrfWim3V8eG4WgdK8xQdzwI=
    github.com/BurntSushi/toml@v0.3.1 h1:WXkYYl6Yr3qBf1K79EBnL4mak0OimBfB0XUf9Vl28OQ=
    github.com/google/go-cmp@v0.5.1 h1:JFrFEBb2xKufg6XkJsJr+WbKb4FQlURi5RUcBveYu9k=
    github.com/sergi/go-diff@v1.1.0 h1:we8PVUC3FE2uYfodKH/nBHMSetSfHDR6scGdBi+erh0=
    golang.org/x/mod@v0.3.0 h1:RM4zey1++hCTbCVQfnWeKs9/IEsaBLA8vTkd0WVtmH4=
    golang.org/x/sync@v0.0.0-20201020160332-67f06af15bc9 h1:SQFwaSi55rU7vdNs9Yr0Z324VNlrF+0wMqRXT4St8ck=
    golang.org/x/tools@v0.0.0-20201211192254-72fbef54948b h1:8fYBhX5ZQZtb7nVKo58TjndJwMM+cOB1xOnfjgH3uiY=
    golang.org/x/xerrors@v0.0.0-20200804184101-5ec99f83aff1 h1:go1bK/D/BFZV2I8cIQd1NKEZ+0owSTG1fDTci4IqFcE=
    honnef.co/go/tools@v0.0.1-2020.1.6 h1:W18jzjh8mfPez+AwGLxmOImucz/IFjpNlrKVnaj2YVc=
    mvdan.cc/gofumpt@v0.0.0-20200927160801-5bfeb2e70dd6 h1:z+/YqapuV7VZPvBb3GYmuEJbA88M3PFUxaHilHYVCpQ=
    mvdan.cc/xurls/v2@v2.2.0 h1:NSZPykBXJFCetGZykLAxaL6SIpvbVy/UFEniIfHAa8A=

Repeating my experiments, the longest textDocument/codeLens operation I observed was around 4000ms. This seems consistent with pre v0.5.5, so I am happy to close this issue.

@golang golang locked and limited conversation to collaborators Dec 14, 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
None yet
Development

No branches or pull requests

3 participants