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.

Sign up for GitHub

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

Jump to bottom

x/tools/gopls: slow in overlay testdata/ packge #34360

Closed
muirdm opened this issue Sep 17, 2019 · 8 comments
Closed

x/tools/gopls: slow in overlay testdata/ packge #34360

muirdm opened this issue Sep 17, 2019 · 8 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.
Milestone
gopls/v0.4.1

Comments

@muirdm
Copy link

muirdm commented Sep 17, 2019

What version of Go are you using (go version)?

$ go version
go version go1.12.9 darwin/amd64

Does this issue reproduce with the latest release?

Yes

What did you do?

I created an overlay package (i.e. not saved on disk) in the tools repo, e.g. tools/internal/lsp/testdata/banana/banana.go with contents "package banana".

What did you expect to see?

I expected gopls to work with reasonable responsiveness.

What did you see instead?

Every change to the file triggered a very slow go/packages call. The changes would queue up, so if I typed 10 characters quickly, it would take 30 seconds before gopls caught up. It was hard to save the file because my organizeImports pre-save hook was getting stuck in the queue as well. Here is the log from one keypress:

2019/09/17 14:37:07 91.159572ms for GOROOT= GOPATH=/Users/muir/projects/<project>/go GO111MODULE= PWD=/Users/muir/projects/tools/ go "env" "GOMOD", stderr: <<>>

2019/09/17 14:37:07 99.643867ms for GOROOT= GOPATH=/Users/muir/projects/<project>/go GO111MODULE= PWD=/Users/muir/projects/tools/ go "list" "-m" "-json" "all", stderr: <<>>

2019/09/17 14:37:09 1.965799648s for GOROOT= GOPATH=/Users/muir/projects/<project>/go GO111MODULE= PWD=/Users/muir/projects/tools/ go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "--" "/Users/muir/projects/tools/internal/lsp/testdata/banana", stderr: <<go: finding golang.org/x/tools/internal/lsp/testdata/banana latest
go: finding golang.org/x/tools/internal/lsp/testdata latest
go: finding golang.org/x/tools/internal/lsp latest
go: finding golang.org/x/tools/internal latest
>>

2019/09/17 14:37:09 25.266872ms for GOROOT= GOPATH=/Users/muir/projects/<project>/go GO111MODULE= PWD=/Users/muir/projects/tools/ go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "--" "/Users/muir/projects/tools/internal/lsp/testdata/banana/banana.go", stderr: <<stat /Users/muir/projects/tools/internal/lsp/testdata/banana/banana.go: no such file or directory
>>

2019/09/17 14:37:10 541.27115ms for GOROOT= GOPATH=/Users/muir/projects/<project>/go GO111MODULE= PWD=/Users/muir/projects/tools/ go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "-mod=readonly" "--" "golang.org/x/tools/internal/memoize" "golang.org/x/tools/internal/telemetry/log" "reflect" "bytes" "golang.org/x/tools/internal/span" "go/scanner" "go/token" "golang.org/x/tools/internal/lsp/protocol" "golang.org/x/tools/internal/telemetry/trace" "go/parser" "golang.org/x/tools/internal/lsp/telemetry" "golang.org/x/tools/internal/lsp/source" "golang.org/x/xerrors" "go/ast" "context", stderr: <<>>
@gopherbot gopherbot added this to the Unreleased milestone Sep 17, 2019
@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 Sep 17, 2019
@gopherbot
Copy link
Contributor

Thank you for filing a gopls issue! Please take a look at the Troubleshooting section of the gopls Wiki page, and make sure that you have provided all of the relevant information here.

@tbhartman
Copy link

I am seeing similarly slow behavior during go list (takes 4-5 seconds per run) when using gopls in VSCode. In my case, I only see the slowdown when editing imports, but the changes are queued such that typing 5 characters leads to 5 times the delay (animation at 20x speed...full time of animation was 1.8 minutes)

20Um0

Log from gopls (not same as animation, but editing imports in a different file):

[Info  - 11:14:17 AM] 2019/09/18 11:14:17 345.9982ms for [redacted] go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "--" "builtin", stderr: <<>>
[Info  - 11:14:17 AM] 2019/09/18 11:14:17 628.9988ms for [redacted] go "list" "-m" "-json" "all", stderr: <<>>
[Info  - 11:14:18 AM] 2019/09/18 11:14:18 845.9969ms for [redacted] go "env" "GOMOD", stderr: <<>>
[Info  - 11:14:18 AM] 2019/09/18 11:14:18 319.9983ms for [redacted] go "env" "GOMOD", stderr: <<>>
[Info  - 11:14:19 AM] 2019/09/18 11:14:19 832.9994ms for [redacted] go "list" "-m" "-json" "all", stderr: <<>>
[Info  - 11:14:23 AM] 2019/09/18 11:14:23 5.0190297s for [redacted] go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "--" [redacted], stderr: <<>>
[Info  - 11:14:23 AM] 2019/09/18 11:14:23 go/packages.Load
[Info  - 11:14:23 AM] 2019/09/18 11:14:23 go/packages.Load
[Info  - 11:14:23 AM] 2019/09/18 11:14:23 go/packages.Load
[Info  - 11:14:24 AM] 2019/09/18 11:14:24 275.9977ms for [redacted] go "env" "GOMOD", stderr: <<>>
[Info  - 11:14:24 AM] 2019/09/18 11:14:24 520.0013ms for [redacted] go "list" "-m" "-json" "all", stderr: <<>>
[Info  - 11:14:29 AM] 2019/09/18 11:14:29 4.2761617s for [redacted] go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "--" [redacted], stderr: <<>>
[Info  - 11:14:29 AM] 2019/09/18 11:14:29 go/packages.Load
[Info  - 11:14:29 AM] 2019/09/18 11:14:29 go/packages.Load
[Info  - 11:14:29 AM] 2019/09/18 11:14:29 go/packages.Load
[Info  - 11:14:34 AM] 2019/09/18 11:14:34 280.9992ms for [redacted] go "list" "-m" "-json" "all", stderr: <<>>
[Info  - 11:14:34 AM] 2019/09/18 11:14:34 739.0044ms for [redacted] go "env" "GOMOD", stderr: <<>>
[Info  - 11:14:39 AM] 2019/09/18 11:14:39 4.6301423s for [redacted] go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "--" [redacted], stderr: <<>>
[Info  - 11:14:39 AM] 2019/09/18 11:14:39 292.9698ms for [redacted] go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "-mod=readonly" "--" "fm", stderr: <<>>
[Info  - 11:14:39 AM] 2019/09/18 11:14:39 go/packages.Load
[Info  - 11:14:39 AM] 2019/09/18 11:14:39 go/packages.Load
[Info  - 11:14:39 AM] 2019/09/18 11:14:39 go/packages.Load
[Info  - 11:14:39 AM] 2019/09/18 11:14:39 503.0017ms for [redacted] go "list" "-m" "-json" "all", stderr: <<>>
[Info  - 11:14:40 AM] 2019/09/18 11:14:40 726.0504ms for [redacted] go "env" "GOMOD", stderr: <<>>
[Info  - 11:14:43 AM] 2019/09/18 11:14:43 4.0372971s for [redacted] go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "--" [redacted], stderr: <<>>
[Info  - 11:14:43 AM] 2019/09/18 11:14:43 265.0874ms for [redacted] go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "-mod=readonly" "--" "fm", stderr: <<>>
[Info  - 11:14:43 AM] 2019/09/18 11:14:43 go/packages.Load
[Info  - 11:14:43 AM] 2019/09/18 11:14:43 go/packages.Load
[Info  - 11:14:43 AM] 2019/09/18 11:14:43 go/packages.Load
[Info  - 11:14:44 AM] 2019/09/18 11:14:44 272.0332ms for [redacted] go "env" "GOMOD", stderr: <<>>
[Info  - 11:14:44 AM] 2019/09/18 11:14:44 718.0346ms for [redacted] go "list" "-m" "-json" "all", stderr: <<>>
[Info  - 11:14:48 AM] 2019/09/18 11:14:48 4.2415797s for [redacted] go "list" "-e" "-json" "-compiled=true" "-test=true" "-export=false" "-deps=true" "-find=false" "--" [redacted], stderr: <<>>
[Info  - 11:14:48 AM] 2019/09/18 11:14:48 go/packages.Load
[Info  - 11:14:48 AM] 2019/09/18 11:14:48 go/packages.Load
[Info  - 11:14:48 AM] 2019/09/18 11:14:48 go/packages.Load

@stamblerre
Copy link
Contributor

@muirrn: By change to the file, do you mean change in the file's imports? That's the only time go/packages should be called.

@tbhartman: What version of gopls are you using? Make sure it's the latest by running go get golang.org/x/tools/gopls@latest. There are some issues with manual imports taking a bit to catch up, but it should never be more than a second. If you are seeing this with v0.1.7, then please open a separate issue, and I will help you debug there. It doesn't seem like your code is necessarily in an overlay.

@muirdm
Copy link
Author

muirdm commented Sep 18, 2019

By change to the file, do you mean change in the file's imports?

No, it was happening after any change until I saved the file. I assume the go/packages call is failing so it keeps retrying after every change.

@stamblerre
Copy link
Contributor

Do overlays behave like this if you use them in other directories? Is it possibly something specific that's strange about the internal/lsp/testdata directory?

@muirdm
Copy link
Author

muirdm commented Sep 19, 2019

I tried it in a non-testdata directory and it is certainly different. It doesn't get stuck, but no LSP features work and I get LSP :: stat /Users/muir/projects/tools/internal/lsp/banana/banana.go: no such file or directory every time I change or do anything (probably a separate issue from testdata).

@muirdm muirdm changed the title x/tools/gopls: slow go/packages call after every change in overlay package x/tools/gopls: slow in overlay testdata/ packge Oct 9, 2019
@muirdm
Copy link
Author

muirdm commented Oct 9, 2019

Do we care about gopls in testdata/ packages? Is it an accident that it works at all, or should it be supported?

@stamblerre stamblerre self-assigned this Nov 7, 2019
@stamblerre stamblerre modified the milestones: Unreleased, gopls v1.0 Dec 4, 2019
@stamblerre stamblerre modified the milestones: gopls/v1.0.0, gopls/v0.4.0 Mar 12, 2020
@stamblerre stamblerre modified the milestones: gopls/v0.4.0, gopls/v0.5.0 Apr 2, 2020
@stamblerre
Copy link
Contributor

stamblerre commented Apr 17, 2020 •
edited
Loading

Do we care about gopls in testdata/ packages? Is it an accident that it works at all, or should it be supported?

I believe one of the goals of go/packages/packagestest was to have testdata that we could use our own tools on. I know that the gopls testdata will only partially work because it has a fake dependency tree, but we do want gopls to work on it to some extent.

I am no longer able to reproduce this, however. I think enough has changed in gopls since this issue was filed that it is no longer relevant. @muirdm, please reopen if you can still repro this.

@stamblerre stamblerre modified the milestones: gopls/v0.5.0, gopls/v0.4.1 May 13, 2020
@golang golang locked and limited conversation to collaborators May 13, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
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.
Projects
None yet
Milestone
gopls/v0.4.1
Development

No branches or pull requests
4 participants
@tbhartman @stamblerre @gopherbot @muirdm