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

cmd/go: indexed packages not invalidated when location of parent go.mod file changes #53586

Closed
findleyr opened this issue Jun 28, 2022 · 10 comments
Assignees
Labels
FrozenDueToAge GoCommand cmd/go gopls Issues related to the Go language server, gopls. release-blocker Tools This label describes issues relating to any tools in the x/tools repository.
Milestone

Comments

@findleyr
Copy link
Contributor

findleyr commented Jun 28, 2022

We have two concerning test failures on the builders, which seem to have the same root cause:

darwin-amd64-10_14: https://build.golang.org/log/88d3fe6fbcfe0ba7110aac537e5cdcae51737d4d
openbsd-386-70: https://build.golang.org/log/79c6a4815792817f70a447fecb4557aa33b90ff0

Both of these are concerning because gopls is failing to find package metadata for a file, even after reloading (and apparently successfully loading file data).

It's suprising that files are left orphaned by the initial metadata load (in a typical run, they aren't). It's also suprising that the reloads (via reloadOrphanedFiles) do not correctly result in the requisite file associations. Logging in those test failures indicates that the loaded packages include the orphaned files, yet they continue to be reloaded (EDIT: my eyes deceived me, the paths don't match! See below).

This is likely related to my recent changes to metadata graph building. I'd like to understand this before releasing gopls@v0.9.0. Unfortunately, it seems exceedingly rare; I will see if I can add more instrumentation and reproduce via slowbots.

CC @adonovan

@findleyr findleyr added this to the gopls/v0.9.0 milestone Jun 28, 2022
@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 Jun 28, 2022
@findleyr
Copy link
Contributor Author

Ok, two new failures just occurred on darwin builders:
https://build.golang.org/log/2a5d73ac2f31f441c1b3a939c5c29addd21f9c1c
https://build.golang.org/log/438b80942ea9ff3a766b43d9fe90516aed97e69a

All things considered this is good news, because hopefully additional instrumentation will allow root causing. Unfortunately, this means this really must block the v0.9.0 release; unless we convince ourselves that there is something incorrect about the setup of internal/lsp tests, this failure rate is certainly high enough to affect our users.

The increased frequency also makes it more likely that a recent change contributed to these failures.

@gopherbot
Copy link

Change https://go.dev/cl/414854 mentions this issue: internal/lsp: add additional instrumentation around package loading

gopherbot pushed a commit to golang/tools that referenced this issue Jun 28, 2022
Add some additional logging to help debug golang/go#53586

For golang/go#53586

Change-Id: I0574fb01be47b265cd6e412855794bc2cb836dff
Reviewed-on: https://go-review.googlesource.com/c/tools/+/414854
gopls-CI: kokoro <noreply+kokoro@google.com>
Reviewed-by: Alan Donovan <adonovan@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Run-TryBot: Robert Findley <rfindley@google.com>
Auto-Submit: Robert Findley <rfindley@google.com>
@findleyr
Copy link
Contributor Author

findleyr commented Jun 29, 2022

Aha! I only just now noticed the asymmetry between query and result, in the test logs

2022/06/28 11:27:39 go/packages.Load
    snapshot=1
    directory=/var/folders/9w/4l2_g3kx01x199n37fbmv3s80000gn/T/workdir-host-darwin-10_14/tmp/gopls-workspace-mod3193680098
    query=[file=/var/folders/9w/4l2_g3kx01x199n37fbmv3s80000gn/T/workdir-host-darwin-10_14/tmp/TestLSP_MultiModule32642401/lsp/testmodule/interfacerank/interface_rank.go]
    packages=1
2022/06/28 11:27:39 go/packages.Load
    snapshot=1
    package="golang.org/x/tools/internal/lsp/interfacerank"
    files=[/var/folders/9w/4l2_g3kx01x199n37fbmv3s80000gn/T/workdir-host-darwin-10_14/tmp/TestLSP_MultiModule32642401/lsp/testmodule/testmodule/interfacerank/interface_rank.go]

Note that we're querying for testmodule/interfacerank/interface_rank.go, but getting back a package containing an extra 'testmodule': testmodule/testmodule/interfacerank/interface_rank.go. This would explain why it only affects the 'MultiModule' run mode, which creates this synthetic module.

Because the load succeeds, we don't mark these files as unloadable and continue to reload them ad-infinitum.

The bug may be in go/packages, or may be in one of the transformations gopls applies. I haven't figured out where the extra 'testmodule' is coming from.

@findleyr
Copy link
Contributor Author

Ok, I've stared at this for a while, reading the gopls, go/packages, go list, and modindex code. With that said, I haven't made much progress.

This appears to be a go list or go/packages bug, perhaps related to the recent change to package indexing? The first failure was shortly after https://go.dev/cl/413815 landed ("cmd/go: add per-package indexing for modules outside mod cache", though I don't necessarily think that CL is implicated).

A few notes:

  • the go.mod file starts out in lsp/go.mod but is moved to lsp/testmodule/go.mod, so perhaps that move could cause the extra "testmodule" due to improper invalidation. That seems plausible, but unlikely because the file move happens before we start up the tests, and therefore should be before we invoke the go command for the first time
  • there are many packages in the module, but only a subset get this bug, which is strange
  • go/packages doesn't appear to verify that GoFile paths match the file=query, only checking basenames. That would allow this bug: https://cs.opensource.google/go/x/tools/+/master:go/packages/golist.go;l=332;drc=7743d1d949f1006ad12b190d68996acafc84d1d6

@bcmills does this type of corruption ring any bells?

@rsc
Copy link
Contributor

rsc commented Jun 30, 2022

I am looking into modindex to understand a performance problem and will look into this behavior too.

@bcmills
Copy link
Member

bcmills commented Jun 30, 2022

I wonder if the per-package index needs to include the corresponding module's go.mod file (contents and location) in the cache key. That could potentially affect the import path and the directory relative to the module root.

@gopherbot
Copy link

Change https://go.dev/cl/415475 mentions this issue: cmd/go: include module root in package index key

@gopherbot
Copy link

Change https://go.dev/cl/415474 mentions this issue: cmd/go: add a 'sleep' command for script tests

@bcmills bcmills self-assigned this Jun 30, 2022
@bcmills bcmills changed the title x/tools/gopls: "no packages" flake of the internal/lsp package cmd/go: indexed packages not invalidated when location of parent go.mod file changes Jun 30, 2022
gopherbot pushed a commit that referenced this issue Jun 30, 2022
Due to mtime skew we don't index mutable packages with an mtime
younger than 2 seconds. In order to test indexed packages reliably, we
want to be able to sleep long enough for the files in the package to be cached.

(As an alternative we could instead use os.Chtimes to fake old enough
timestamps, but sleeping keeps the tests more realistic.)

For #53586.

Change-Id: I1873f47c55a72d928451593b8c989f0092a557db
Reviewed-on: https://go-review.googlesource.com/c/go/+/415474
Auto-Submit: Bryan Mills <bcmills@google.com>
Run-TryBot: Bryan Mills <bcmills@google.com>
Reviewed-by: Russ Cox <rsc@golang.org>
TryBot-Result: Gopher Robot <gobot@golang.org>
@gopherbot
Copy link

Change https://go.dev/cl/415514 mentions this issue: cmd/go/internal/modindex: remove spurious field from index_format documentation

@findleyr
Copy link
Contributor Author

findleyr commented Jun 30, 2022

Ok, the final piece of the puzzle: the packagestest runner actually does invoke the go command before calling the test function, here:
https://cs.opensource.google/go/x/tools/+/master:go/packages/packagestest/modules.go;l=187;drc=d5f48fca5379171ebce583082a3dd683c8f8ad75
EDIT: that wouldn't do it, but this would: https://cs.opensource.google/go/x/tools/+/master:go/packages/packagestest/expect.go;l=153;drc=facb0d30e9e8a14e6e9b3f3df1f49b003391d5f4

And then inside the test function, the go.mod is moved: https://cs.opensource.google/go/x/tools/+/master:internal/lsp/tests/tests.go;l=505;drc=ebc084af8ba794babff1d58912b41608629acd72)

So now everything makes sense.

gopherbot pushed a commit that referenced this issue Jun 30, 2022
…umentation

The 'path' field was removed in an earlier revision to the format.

While auditing the format, I also cleaned up a couple of minor
typographical issues.

For #53586.

Change-Id: I4cd1ce9e970023441c11244428ed2971be1d8138
Reviewed-on: https://go-review.googlesource.com/c/go/+/415514
Reviewed-by: Ian Lance Taylor <iant@google.com>
Run-TryBot: Bryan Mills <bcmills@google.com>
Auto-Submit: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
jproberts pushed a commit to jproberts/go that referenced this issue Aug 10, 2022
Due to mtime skew we don't index mutable packages with an mtime
younger than 2 seconds. In order to test indexed packages reliably, we
want to be able to sleep long enough for the files in the package to be cached.

(As an alternative we could instead use os.Chtimes to fake old enough
timestamps, but sleeping keeps the tests more realistic.)

For golang#53586.

Change-Id: I1873f47c55a72d928451593b8c989f0092a557db
Reviewed-on: https://go-review.googlesource.com/c/go/+/415474
Auto-Submit: Bryan Mills <bcmills@google.com>
Run-TryBot: Bryan Mills <bcmills@google.com>
Reviewed-by: Russ Cox <rsc@golang.org>
TryBot-Result: Gopher Robot <gobot@golang.org>
jproberts pushed a commit to jproberts/go that referenced this issue Aug 10, 2022
The package index format includes the directory relative to the module
root. The module root for a given directory can change even if the
contents of the directory itself do not (by adding or removing a
go.mod file in some parent directory).

Thus, we need to invalidate the index for a package when its module
root location changes.

Fixes golang#53586 (I think).

Change-Id: I2d9f4de80e16bce75b3106a2bad4a11d8378d037
Reviewed-on: https://go-review.googlesource.com/c/go/+/415475
Reviewed-by: Russ Cox <rsc@golang.org>
Auto-Submit: Bryan Mills <bcmills@google.com>
Run-TryBot: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
jproberts pushed a commit to jproberts/go that referenced this issue Aug 10, 2022
…umentation

The 'path' field was removed in an earlier revision to the format.

While auditing the format, I also cleaned up a couple of minor
typographical issues.

For golang#53586.

Change-Id: I4cd1ce9e970023441c11244428ed2971be1d8138
Reviewed-on: https://go-review.googlesource.com/c/go/+/415514
Reviewed-by: Ian Lance Taylor <iant@google.com>
Run-TryBot: Bryan Mills <bcmills@google.com>
Auto-Submit: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
@golang golang locked and limited conversation to collaborators Jun 30, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge GoCommand cmd/go gopls Issues related to the Go language server, gopls. release-blocker Tools This label describes issues relating to any tools in the x/tools repository.
Projects
None yet
Development

No branches or pull requests

4 participants