x/tools/gopls: long initial workspace load durations for workspace with many packages

[rma-stripe]

gopls version

Build info
----------
golang.org/x/tools/gopls (devel)
    golang.org/x/tools/gopls@(devel)
    github.com/BurntSushi/toml@v1.2.1 h1:9F2/+DoOYIOksmaJFPw1tGFy1eDnIJXg+UHjuD8lTak=
    github.com/google/go-cmp@v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI=
    golang.org/x/exp/typeparams@v0.0.0-20221212164502-fae10dda9338 h1:2O2DON6y3XMJiQRAS1UWU+54aec2uopH3x7MAiqGW6Y=
    golang.org/x/mod@v0.21.0 h1:vvrHzRwRfVKSiLrG+d4FMl/Qi4ukBCE6kZlTUkDYRT0=
    golang.org/x/sync@v0.8.0 h1:3NFvSEYkUoMifnESzZl15y791HH1qU2xm6eCJU5ZPXQ=
    golang.org/x/telemetry@v0.0.0-20240829154258-f29ab539cc98 h1:Wm3cG5X6sZ0RSVRc/H1/sciC4AT6HAKgLCSH2lbpR/c=
    golang.org/x/text@v0.18.0 h1:XvMDiNzPAl0jr17s6W9lcaIhGUfUORdGCNsuLmPG224=
    golang.org/x/tools@v0.21.1-0.20240508182429-e35e4ccd0d2d => ../
    golang.org/x/vuln@v1.0.4 h1:SP0mPeg2PmGCu03V+61EcQiOjmpri2XijexKdzv8Z1I=
    honnef.co/go/tools@v0.4.7 h1:9MDAWxMoSnB6QoSqiVr7P5mtkT9pOc1kSxchzPCnqJs=
    mvdan.cc/gofumpt@v0.7.0 h1:bg91ttqXmi9y2xawvkuMXyvAA/1ZGJqYAEGjXuP0JXU=
    mvdan.cc/xurls/v2@v2.5.0 h1:lyBNOm8Wo71UknhUs4QTFUNNMyxy2JEIaKKo0RWOh+8=
go: go1.23.1

go env

$ bin/go env
GO111MODULE=''
GOARCH='arm64'
GOBIN=''
GOCACHE='/Users/rma/Library/Caches/go-build'
GOENV='/Users/rma/Library/Application Support/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='arm64'
GOHOSTOS='darwin'
GOINSECURE=''
GOMODCACHE='/Users/rma/go/pkg/mod'
GONOPROXY=<REDACTED>
GONOSUMDB=<REDACTED>
GOOS='darwin'
GOPATH='/Users/rma/go'
GOPRIVATE=<REDACTED>
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/Users/rma/.cache/gocode/sdk/1.22'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/Users/rma/.cache/gocode/sdk/1.22/pkg/tool/darwin_arm64'
GOVCS=''
GOVERSION='go1.22.6'
GCCGO='gccgo'
AR='ar'
CC='clang'
CXX='clang++'
CGO_ENABLED='1'
GOMOD='/Users/rma/stripe/gocode/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -arch arm64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -ffile-prefix-map=/var/folders/wc/_g6hd_8d3dnb87c04x67w0l40000gn/T/go-build681359692=/tmp/go-build -gno-record-gcc-switches -fno-common'

What did you do?

My organization within the company is responsible for maintaining a large Go monorepo (~20k packages). In this monorepo, all packages fall under 1 Go module.

For the most part, we run a fairly off-the-shelf gopls setup without any customization of note. This is what our stats look like (from bea7373d8a8268c2e3a260c1b8d41f96c4f7489e):

$ gopls stats -anon
Initializing workspace...     done (3m26.109285333s)
Gathering bug reports...      done (1.781858458s)
Querying memstats...          done (1.284304292s)
Querying workspace stats...   done (701.076375ms)
Collecting directory info...  done (7.958301292s)
{
  "DirStats": {
    "Files": 288174,
    "TestdataFiles": 8243,
    "GoFiles": 77688,
    "ModFiles": 20,
    "Dirs": 64532
  },
  "GOARCH": "arm64",
  "GOOS": "darwin",
  "GOPACKAGESDRIVER": "",
  "GOPLSCACHE": "",
  "GoVersion": "go1.23.1",
  "GoplsVersion": "(devel)",
  "InitialWorkspaceLoadDuration": "3m26.109285333s",
  "MemStats": {
    "HeapAlloc": 2970803424,
    "HeapInUse": 4669145088,
    "TotalAlloc": 36820682064
  },
  "WorkspaceStats": {
    "Files": {
      "Total": 72996,
      "Largest": 9189430,
      "Errs": 0
    },
    "Views": [
      {
        "GoCommandVersion": "go1.22.0",
        "AllPackages": {
          "Packages": 23170,
          "LargestPackage": 624,
          "CompiledGoFiles": 89502,
          "Modules": 1031
        },
        "WorkspacePackages": {
          "Packages": 18127,
          "LargestPackage": 354,
          "CompiledGoFiles": 61173,
          "Modules": 1
        },
        "Diagnostics": 95
      }
    ]
  }
}

What did you see happen?

The experience of using gopls is good (i.e. rpcs like jump-to-definition, refactor symbol, etc. are fast) once initial workspace load has occurred, but initial workspace loads are a poor experience for our users. This poor experience is owed to two behaviors:

Firstly, initial workspace loads (IWLs) are slow. This is partially owed to the performance of the expensive upfront go list call itself:

$ time go list -e -json=Name,ImportPath,Error,Dir,GoFiles,IgnoredGoFiles,IgnoredOtherFiles,CFiles,CgoFiles,CXXFiles,MFiles,HFiles,FFiles,SFiles,SwigFiles,SwigCXXFiles,SysoFiles,TestGoFiles,XTestGoFiles,CompiledGoFiles,Export,DepOnly,Imports,ImportMap,TestImports,XTestImports,ForTest,DepsErrors,Module,EmbedFiles -compiled=true -test=true -export=false -deps=true -find=false -pgo=off -- /Users/rma/stripe/gocode/... builtin
[ ...A bunch of redacted `go list` output... ]
go list -e  -compiled=true -test=true -export=false -deps=true -find=false  -  31.41s user 48.00s system 120% cpu 1:06.01 total

…but the majority of the time is spent on calling packages.Load on all of the packages that go list returns.

Secondly, because IWLs are blocking and VSCode waits on code actions before the IDE is able to save files, users are unable to save files/exit their IDEs/etc:

Saving 'main.go': Getting code actions from ''Go', 'ESLint', 'GitHub Copilot Chat'' (configure).

…while IWL is incomplete. This is partially a corollary of the first issue. While it is true that making code actions non-blocking for saves would fix this UX issue, if IWL were fast, this UX issue would not be perceived by users in the first place.

We have dipped our toes in trying to patch this behavior. For example, an early attempt at hacking around this behavior (on a v1.16.1 base) no-ops the initialization routine altogether, relying solely on gopls loading in package data as files are manually opened by the user. As expected, this hack has some large tradeoffs associated with it, because initialization is a load bearing part of gopls: it breaks features like "Rename symbol" and "Find all references", and it occasionally causes the wrong imports to be pulled in. However, buggy as it is, this hack in essence describes what we think the desirable IWL behavior would be:

• The initial snapshot at gopls startup does not await IWL
• On startup, an async IWL routine runs go list and lazy loads package data into the currently "active" snapshot
• While this async routine has not completed, language server RPCs which rely on all workspace packages being loaded (such as "Find all references" are not available)

What did you expect to see?

This issue is a feature request.

• Does the newly proposed workspace initialization approach align with the gopls roadmap?
• Is there a better approach (in the interim) to addressing the slow/blocking behavior of IWLs than the no-op/hack solution linked above?

We would appreciate any tips/guidance in writing an upstream-able patch, or a better hack.

Editor and settings

No response

Logs

No response

[gabyhelp]

Related Issues and Documentation

• x/tools/gopls: high memory consumption when used with a monorepo #37670 (closed)
• x/tools/gopls: add ability to avoid scanning an entire workspace #53278 (closed)
• x/tools/gopls: init project cost long time when open the go project #62715 (closed)
• x/tools/gopls: too many memory usage #37759 (closed)
• x/tools/gopls: crash importing test variant of tools file #66109 (closed)
• x/tools/gopls: feedback is extremely slow with large monorepo #44188 (closed)
• cmd/go: `go list` commands called by `golang.org/x/tools/go/packages.Load()` varies from ~500ms to 3s with no other changes #63863 (closed)
• x/tools/gopls: massive cpu and memory usage #46897 (closed)
• x/tools/gopls: gopls walks entire filesystem of a go module #52993 (closed)
• x/tools/imports: should not scan bazel-out directories #35914

_{(Emoji vote if this was helpful or unhelpful; more detailed feedback welcome in this discussion.)}

[findleyr]

Thanks for filing this thoughtful issue.

I've wanted the ability to bypass the initial workspace load for a while. This is in line with the work in https://go.dev/issue/68002, which I'm working my way up to now.

I expect this to be doable, though there will almost certainly be many edge cases to take care of (for example: producing reasonable errors for workspace-wide misconfiguration).

[findleyr]

So, I "got this working" today, in the sense that I removed the guardrails preventing gopls from working prior to the initial workspace load. In principle, I think the guardrails are misguided anyway: we don't enforce the same restrictions when reloading a workspace (for example, after making a go.mod change), so there's really no reason we can't allow gopls to function prior to the initial workspace load.

However, the change actually poses a significant challenge for testing, since we seek the completion of the initial workspace load in many places as a signal that gopls is ready to be used. Now there is no such signal.

@rma-stripe I'm curious if patching the following CL and installing gopls works well for you. That would at least be a signal that we're on the right track.
https://go.dev/cl/626536

…but the majority of the time is spent on calling packages.Load on all of the packages that go list returns.

That's surprising to me. Can you say more? I'd expect the post-processing of packages should be a minor cost. Certainly gopls type checking those packages can take a while, but that is not considered to be part of the initial workspace load.

[rma-stripe]

 I'm curious if patching the following CL and installing gopls works well for you. That would at least be a signal that we're on the right track.

In general the patch works well. I was able to visually time when the initial workspace load completes by looking for the (*Snapshot).load event with the same query + number of packages as event #1: https://gist.github.com/rma-stripe/d14b1336fcea83672ef15b41d3cdab05

Prior to the initial workspace load's completion, features like jump-to-definition and definition-on-highlight work. Some other features, like "Find all references" are blocked on the initial workspace load completion, which makes sense, as we can't find all references to a symbol without introspecting the whole workspace.

An issue I was only able to repro once: By repeatedly opening not-yet-loaded packages by hand (maybe one every 5 seconds) prior to the initial workspace load's completion, I was able to get gopls in a stalled/jammed state where it would not create (*Snapshot).load events for individual files (whether on file open or on file save-after-change) until the initial workspace load succeeded.

Were this patch upstreamed, we would consider it a significant improvement over the current behavior of gopls in our custom-patched version.

That's surprising to me. Can you say more? I'd expect the post-processing of packages should be a minor cost. Certainly gopls type checking those packages can take a while, but that is not considered to be part of the initial workspace load.

I don't fully remember what this was about, sorry. We did some work prior to filing this issue trying to figure out what parts of IWL are slow, but the details of those experiments have since been deleted by our Slack retention policy.

[findleyr]

An issue I was only able to repro once: By repeatedly opening not-yet-loaded packages by hand (maybe one every 5 seconds) prior to the initial workspace load's completion, I was able to get gopls in a stalled/jammed state where it would not create (*Snapshot).load events for individual files (whether on file open or on file save-after-change) until the initial workspace load succeeded.

What could have happened there is this: if you ran a find-references request, it would have blocked other requests, and would itself have awaited initialization. Does that sound plausible? If we were to land this CL, we'd also want to allow navigation to be handled asynchronously to workspace-wide requests. The good news is that we recently added a mechanism for such concurrency.

If we're going to land this, we need to do approximately the following:

• Allow Snapshots to share the view initialization query. Otherwise, each keystroke cancels the previous initializatoin and starts afresh. Instead, we can record overlays that have changed since the last query, and invalidate its results when it completes.
• Have a more general mechanism for raising a progress dialog for the initialization query. For analysis, we raise a popup only if analysis takes longer than 5 seconds. We can do the same for loads.
• Have a better detection mechanism for the completion of the initial workspace load, for the purposes of testing.

This is a non-trivial amount of work -- at least several days work to do it properly. However, I do think it's worth doing as it can really improve the experience of using gopls on large codebases.

[findleyr]

Investigating code paths that await initialization, there are a number of perhaps surprising conditions to sort out. Notably, if you open a file outside a workspace folder, and ask for file-oriented information about that file, gopls currently awaits initialization of each workspace folder, because it has to see which build that file most logically "belongs" to. I suspect this is what occurred to get @rma-stripe's session into a blocked state.

This mechanism is particularly gnarly, because we really don't want to allow other messages to proceed until we've resolved the correct build for that file request, because we need to acquire the Snapshot (a logical point in time) before we allow other state-affecting notifications to be processed.

[rma-stripe]

What could have happened there is this: if you ran a find-references request, it would have blocked other requests, and would itself have awaited initialization. Does that sound plausible?

I think it was likely some other edge case. If this were true, you could repro by:

1. Starting a fresh VSCode
2. Prior to IWL completion, run a find-references request
3. Still prior to IWL completion, open another (unindexed) package and hover over a symbol, and observe that the symbol definition doesn't appear

However, the very last part of Step 3 ("observe that the symbol definition doesn't appear") doesn't hold true, because opening a new file in VSCode causes the find-references context to cancel:

[Error - 1:56:57 PM] Request textDocument/references failed.
  Message: context canceled
  Code: 0 

So long as the context cancelation for the workspace-wide req reliably occurs, the IDE shouldn't get into such a jammed state. Maybe that allows for landing the changeset without blocking it on "allow[ing] navigation to be handled asynchronously to workspace-wide requests", maybe not?

[vinibali]

Hello there!
This also affects me after VScode start initializing the workspace and literally never ends:

[Info  - 11:45:09 PM] 2024/11/14 11:45:09 background imports cache refresh starting

Mostly the huge CPU usage comes after gopls will be triggered with a new file save (and fixing the indentations) or something else. "go clean -modcache" didn't help.
I was using the golang-1.21 packages from official Ubuntu 22.04 repositories and just recently update to the 1.23.

$ bin/gopls stats
Initializing workspace...     done (18.624008221s)
Gathering bug reports...      done (26.125526ms)
Querying memstats...          done (81.075002ms)
Querying workspace stats...   done (3.052773ms)
Collecting directory info...  done (696.553888ms)
{
  "BugReports": [],
  "CacheDir": "/home/user/.cache/gopls/da3c4210",
  "DirStats": {
    "Files": 95939,
    "TestdataFiles": 25739,
    "GoFiles": 56653,
    "ModFiles": 566,
    "Dirs": 20733
  },
  "GOARCH": "amd64",
  "GOOS": "linux",
  "GOPACKAGESDRIVER": "",
  "GOPLSCACHE": "",
  "GoVersion": "go1.23.3",
  "GoplsVersion": "v0.16.2",
  "InitialWorkspaceLoadDuration": "18.624008221s",
  "MemStats": {
    "HeapAlloc": 23729544,
    "HeapInUse": 45809664,
    "TotalAlloc": 239617712
  },
  "WorkspaceStats": {
    "Files": {
      "Total": 1178,
      "Largest": 395026,
      "Errs": 0
    },
    "Views": [
      {
        "GoCommandVersion": "go1.23.3",
        "AllPackages": {
          "Packages": 320,
          "LargestPackage": 165,
          "CompiledGoFiles": 1177,
          "Modules": 1
        },
        "WorkspacePackages": {
          "Packages": 163,
          "LargestPackage": 65,
          "CompiledGoFiles": 268,
          "Modules": 1
        },
        "Diagnostics": 190
      }
    ]
  }
}