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: go get hits proxy to check retracted versions for transitive dependencies too much #42185

Closed
myitcv opened this issue Oct 24, 2020 · 6 comments
Labels
FrozenDueToAge GoCommand cmd/go NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker ToolSpeed
Milestone

Comments

@myitcv
Copy link
Member

myitcv commented Oct 24, 2020

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

$ go version
go version devel +4a2cc73f87 Fri Oct 23 14:18:27 2020 +0000 linux/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/myitcv/.cache/go-build"
GOENV="/home/myitcv/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/myitcv/gostuff/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/myitcv/gostuff"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/myitcv/gos"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/myitcv/gos/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/tmp/tmp.OKr5fuWb4v/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-build599471778=/tmp/go-build -gno-record-gcc-switches"

What did you do?

This is a follow up to an exchange with @jayconrod in #tools on Slack:

https://gophers.slack.com/archives/C0VPK4Z5E/p1603464236390000

Consider the following:

$ cd $(mktemp -d)
$ go mod init mod.com
go: creating new go.mod: module mod.com
$ time go get cuelang.org/go
go: cuelang.org/go upgrade => v0.2.2

real    0m6.058s
user    0m0.739s
sys     0m0.225s
$ time go get cuelang.org/go

real    0m3.311s
user    0m0.436s
sys     0m0.254s
$ time go get cuelang.org/go@v0.2.2

real    0m3.240s
user    0m0.428s
sys     0m0.266s

Running the above with a local GOMODCACHE that is already "warm" (i.e. fully populated from a previous go mod download where cuelang.org/go@v0.2.2 is a dependency).

  • The initial go get takes too long
  • The subsequent go get's also take too long

The time on subsequent go get's appears to be taken checking version lists of transitive dependencies:

...
# get https://proxy.golang.org/cloud.google.com/go/@v/list
# get https://proxy.golang.org/cloud.google.com/go/@v/list: 200 OK (0.015s)
# get https://proxy.golang.org/dmitri.shuralyov.com/gpu/mtl/@v/list
# get https://proxy.golang.org/dmitri.shuralyov.com/gpu/mtl/@v/list: 200 OK (0.024s)
# get https://proxy.golang.org/dmitri.shuralyov.com/gpu/mtl/@latest
# get https://proxy.golang.org/dmitri.shuralyov.com/gpu/mtl/@latest: 200 OK (0.025s)
# get https://proxy.golang.org/github.com/%21burnt%21sushi/toml/@v/list
# get https://proxy.golang.org/github.com/%21burnt%21sushi/toml/@v/list: 200 OK (0.022s)
# get https://proxy.golang.org/github.com/%21burnt%21sushi/xgb/@v/list
...

It is unclear why the initial go get takes almost twice as long.

Also, if you follow, in real time, the output of go get -x cuelang.org/go@v0.2.2, assuming the output is representative of the real time execution of go get, the checking of the version lists of the transitive dependencies appears to happen in serial rather than "as concurrently as possible". (It could of course be that the proxy is doing some sort of rate limiting, but I find that harder to believe)

What did you expect to see?

Fast execution of all the above commands, because my GOMODCACHE is already warm.

What did you see instead?

The above.

Per our discussion, this feels like a fairly significant backwards step in terms of "performance". If this is all attributable to the checking of retracted versions, then I think we need to consider that check being a separate command rather than magically happening as part of other commands.

cc @jayconrod @bcmills @matloob

@myitcv myitcv added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. GoCommand cmd/go labels Oct 24, 2020
@jayconrod
Copy link
Contributor

Thanks for opening this. I'll look into it and see if we can speed things up.

I don't think retraction should be gated by a flag in go get because it's very important that users don't automatically upgrade to retracted versions without explicitly requesting them. In the common case where there are no retractions (or where the highest version is not retracted), that should result in no additional requests.

I think most of the delay here is coming from checking retractions on modules not being upgraded, so we can print out a warning at the end, prompting the user to upgrade. That's probably not worth taking a lot of time though; the same information is available from go get -m -u.

@jayconrod jayconrod added this to the Go1.16 milestone Oct 26, 2020
@rogpeppe
Copy link
Contributor

rogpeppe commented Nov 5, 2020

I don't know if this is hitting the same issue, but I also find that go get is weirdly slow compared to go mod tidy when it's doing exactly the same job. Here's a recent transcript:

% git checkout  ../../go.mod ../../go.sum
Updated 2 paths from the index
% time  go get github.com/frankban/quicktest
go: github.com/frankban/quicktest upgrade => v1.11.2
2.71user 0.54system 0:15.59elapsed 20%CPU (0avgtext+0avgdata 33320maxresident)k
744inputs+0outputs (11major+11285minor)pagefaults 0swaps
% git checkout  ../../go.mod ../../go.sum
Updated 2 paths from the index
% time go mod tidy
0.84user 0.23system 0:00.23elapsed 468%CPU (0avgtext+0avgdata 31380maxresident)k
0inputs+0outputs (0major+6014minor)pagefaults 0swaps
% git diff ../../go.mod
diff --git a/go.mod b/go.mod
index b4bd9aaac..884a086ab 100644
--- a/go.mod
+++ b/go.mod
@@ -52,6 +52,7 @@ require (
 	github.com/evanphx/json-patch v4.2.0+incompatible // indirect
 	github.com/fatih/color v1.9.0
 	github.com/fatih/structs v1.1.0
+	github.com/frankban/quicktest v1.4.1
 	github.com/getkin/kin-openapi v0.2.0
 	github.com/ghodss/yaml v1.0.0
 	github.com/gin-gonic/gin v1.6.2

go mod tidy is more than 50x faster than go get, despite doing more.

@bcmills
Copy link
Contributor

bcmills commented Nov 5, 2020

@rogpeppe, go mod tidy should only be checking retractions for newly-added (or newly-changed) modules, not existing ones.

@rogpeppe
Copy link
Contributor

rogpeppe commented Nov 5, 2020

In this case, there is only one newly added package in both cases, so ISTM that go mod tidy is doing strictly more because it's checking a load of other stuff too (eg unused modules)

@gopherbot
Copy link

Change https://golang.org/cl/269019 mentions this issue: cmd/go: in 'go get', only load retractions for resolved versions

@gopherbot
Copy link

Change https://golang.org/cl/270858 mentions this issue: cmd/go: in 'go get', only load retractions for resolved versions

gopherbot pushed a commit that referenced this issue Nov 18, 2020
Previously, 'go get' loaded retractions for every module in the build
list, which took a long time and usually wasn't helpful.

This rolls forward CL 269019, which was reverted in CL 270521. The new
revision adds a call to modload.ListModules at the end of 'go get' to
ensure .info files are cached for everything in the build list.

Fixes #42185

Change-Id: I684f66c5e674384d5a0176fbc8317e5530b8a915
Reviewed-on: https://go-review.googlesource.com/c/go/+/270858
Trust: Jay Conrod <jayconrod@google.com>
Reviewed-by: Bryan C. Mills <bcmills@google.com>
@golang golang locked and limited conversation to collaborators Nov 17, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge GoCommand cmd/go NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker ToolSpeed
Projects
None yet
Development

No branches or pull requests

5 participants