search

golang / go

The Go programming language
https://go.dev
BSD 3-Clause "New" or "Revised" License
124.26k stars 17.7k forks source link

proxy.golang.org: slow to update with latest version information #42449

Closed myitcv closed 4 years ago

myitcv commented 4 years ago

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

$ go version
go version devel +3ef8562c9c Thu Nov 5 02:48:05 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"
GOVCS=""
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/tmp/tmp.GJhX78qxmg/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-build655069535=/tmp/go-build -gno-record-gcc-switches"

What did you do?

$ go version
go version devel +3ef8562c9c Thu Nov 5 02:48:05 2020 +0000 linux/amd64
$ mkdir /home/gopher/proverb
$ cd /home/gopher/proverb
$ git init -q
$ git remote add origin https://example.com/proverb.git
$ go mod init example.com/proverb
go: creating new go.mod: module example.com/proverb
$ cat <<EOD > /home/gopher/proverb/proverb.go
package proverb

// Go returns a Go proverb
func Go() string {
    return "Don't communicate by sharing memory, shard memory by communicating."
}

EOD
$ git add -A
$ git commit -q -m "Initial commit"
$ git push -q origin main
remote: . Processing 1 references        
remote: Processed 1 references in total        
$ git tag v0.1.0
$ git push -q origin v0.1.0
remote: . Processing 1 references        
remote: Processed 1 references in total        
$ mkdir /home/gopher/gopher
$ cd /home/gopher/gopher
$ go mod init gopher
go: creating new go.mod: module gopher
$ cat <<EOD > /home/gopher/gopher/gopher.go
package main

import (
    "fmt"

    "example.com/proverb"
)

func main() {
    fmt.Println(proverb.Go())
}

EOD
$ go get example.com/proverb@v0.1.0
go: downloading example.com/proverb v0.1.0
$ go run .
Don't communicate by sharing memory, shard memory by communicating.
$ cd /home/gopher/proverb
$ cat <<EOD > /home/gopher/proverb/proverb.go
package proverb

// Go returns a Go proverb
func Go() string {
    return "Concurrency is parallelism."
}

EOD
$ git add -A
$ git commit -q -m "Switch Go proverb to something more famous"
$ git push -q origin main
remote: . Processing 1 references        
remote: Processed 1 references in total        
$ git tag v0.2.0
$ git push -q origin v0.2.0
remote: . Processing 1 references        
remote: Processed 1 references in total        
$ cd /home/gopher/gopher
$ go get example.com/proverb@v0.2.0
go: downloading example.com/proverb v0.2.0
$ go list -m -versions example.com/proverb
example.com/proverb v0.1.0

What did you expect to see?

The call to go list -m -versions reflect the version we have just pulled through the proxy

What did you see instead?

Only the previous version. Indeed I need to wait "some time" before the call to go list "updates".

Discovered whilst trying out module retraction in tip (although I don't believe it is anything to do with module retraction)

The discontinuity between the fact that I can go get that version but can't go list it, makes for harder explanation to the user.

cc @katiehockman @heschik

myitcv commented 4 years ago

The main issue I see arising from the aforementioned discontinuity is that despite the proxy being "aware" of a later version, if it doesn't report that latest version via the versions endpoint, then module retraction will appear not to work as expected, until the versions endpoint does update.

cc @jayconrod

myitcv commented 4 years ago

Indeed this is most evident when a later version issues a retraction that includes that later version (the scenario here is when you want to retract an accidental v1.0.0). Pulling that version through the proxy via go get does not cause the go: warning: $mod@$version is retracted message to be printed. That message is only printed when the versions endpoint updates to include the latest version.

hyangah commented 4 years ago

@myitcv how much is the delay ("some time") you observed?

myitcv commented 4 years ago

I would say anywhere between 15-40 seconds. But as you can see from the following log, it takes some time for that to become a consistent answer, and in the intervening time the answer can "revert" to the previous state. And this is, I think, the behaviour I have observed in #42451.

The scenario leading up to the following log is that v0.1.0, v0.2.0 and v0.3.0 have been published (v0.3.0 retracts v0.2.0 if that is important). The proxy knows about all three versions because I've pulled them through with go get.

The log below is the output from repeated calls to go list -x -m -retracted -versions gopher.live/ub8cdaaf9d101/proverb. Each request is followed by a 1 second delay. The requests stop once 10 consecutive requests return the target state, i.e. v0.1.0 v0.2.0 v0.3.0. 

# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.108s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.108s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.105s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.114s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.120s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.164s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.101s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.100s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.100s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.109s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.108s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.106s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.106s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.110s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.099s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.116s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.099s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.107s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.099s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.096s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.100s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.106s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.106s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.117s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.104s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.111s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.097s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.104s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.103s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.108s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.106s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.110s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.119s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.105s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.113s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.114s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.132s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.108s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.103s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.107s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.101s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.113s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.105s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list
# get https://proxy.golang.org/gopher.live/ub8cdaaf9d101/proverb/@v/list: 200 OK (0.114s)
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
gopher.live/ub8cdaaf9d101/proverb v0.1.0 v0.2.0 v0.3.0
hyangah commented 4 years ago

The list query response from proxy.golang.org uses ~1min TTL for HTTP caching purpose (+ a small delay to reflect the change in our distributed database). I thought this HTTP caching effect was discussed previously.

cc @katiehockman @heschik

heschi commented 4 years ago

From proxy.golang.org:

I committed a new change (or released a new version) to a repository, why isn't it showing up when I run go get -u or go list -m --versions? In order to improve our services' caching and serving latencies, new versions may not show up right away. If you want new code to be immediately available in the mirror, then first make sure there is a semantically versioned tag for this revision in the underlying source repository. Then explicitly request that version via go get module@version. After one minute for caches to expire, the go command will see that tagged version. If this doesn't work for you, please file an issue.

myitcv commented 4 years ago

Thanks for reconfirming.

I thought this HTTP caching effect was discussed previously.

Yes indeed it has been, and is clearly documented on the proxy.golang.org website.

The confusing aspect of this issue and #42451 (to me at least) has been the inconsistent results during that ~1 minute+ that follows a go get. I had (incorrectly) assumed that results after the first "updated" response would be consistent.

From a documentation perspective, should I therefore say "now wait 2 minutes for proxy.golang.org to update"?

jayconrod commented 4 years ago

@heschik told me that cache coherency is not guaranteed. I think you're seeing different requests hitting different instances.

The go command itself caches those requests in memory, so you won't see inconsistent results within a single invocation.

myitcv commented 4 years ago

Thanks everyone for your responses. I'm going to close this issue on the basis things are working as expected and documented. My confusion was indeed an incorrect expectation of cache coherency.