search

gomods / athens

A Go module datastore and proxy
https://docs.gomods.io
MIT License
4.38k stars 492 forks source link

500 Internal Server Error while reading google.golang.org/api/@v/v0.15.1-0.20200106000736-b8fc810ca6b5.mod #1690

Open bnrjee opened 3 years ago

bnrjee commented 3 years ago

Describe the bug We are trying to build few projects and using athens as a proxy with an s3 bucket at the back-end. Build fails for the following repositories, https://github.com/kubernetes-csi/external-snapshotter https://github.com/kubernetes-csi/external-provisioner

Error Message If applicable add error message to help explain your problem or console output enclose in triple back-ticks eg,

```console
+ CGO_ENABLED=0
+ GOOS=linux
+ GOARCH=amd64
+ go build -a -ldflags '-X main.version=v3.0.2-0-g271a825f -extldflags "-static"' -o ./bin/snapshot-controller ./cmd/snapshot-controller
go: k8s.io/kubernetes@v1.19.0 requires
    github.com/GoogleCloudPlatform/k8s-cloud-provider@v0.0.0-20200415212048-7901bc822317 requires
    google.golang.org/api@v0.15.1-0.20200106000736-b8fc810ca6b5: reading http://athens-proxy.default.svc.cluster.local/google.golang.org/api/@v/v0.15.1-0.20200106000736-b8fc810ca6b5.mod: 500 Internal Server Error
```

To Reproduce Steps to reproduce the behavior: Build the aforementioned repositories with athens with an s3 bucket as storage. Expected behavior Builds should succeed.

Environment (please complete the following information): go version go version go1.13.15 linux/amd64 go env
GO111MODULE="" GOARCH="amd64" GOBIN="" GOCACHE="/root/.cache/go-build" GOENV="/root/.config/go/env" GOEXE="" GOFLAGS="" GOHOSTARCH="amd64" GOHOSTOS="linux" GONOPROXY="" GONOSUMDB="" GOOS="linux" GOPATH="/home/prow/go" GOPRIVATE="" GOPROXY="http://athens-proxy.default.svc.cluster.local" GOROOT="/usr/local/go" GOSUMDB="sum.golang.org" GOTMPDIR="" GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64" GCCGO="gccgo" AR="ar" CC="gcc" CXX="g++" CGO_ENABLED="1" GOMOD="" 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-build811031637=/tmp/go-build -gno-record-gcc-switches"

Additional context We are building athens by ourselves from it's latest source code. We have decided not to use any stable release for now because for this to work on our setup we need a new release with this PR.

We built Athens with different go versions, such as go1.13.15, go1.14.13 and go1.15.6. But our builds fail.

To debug a bit further, I made some changes in Athens code in my fork. And got these following logs,

-----------------------------------------------------
DEBUG[5:39PM]: saving google.golang.org/api@v0.15.1-0.20200106000736-b8fc810ca6b5 to storage... http-method=GET http-path=/google.golang.org/api/@v/v0.15.1-0.20200106000736-b8fc810ca6b5.mod request-id=a7fffc12-d276-403e-87b6-5f6f9f4f197e
2020/12/24 17:39:03 DEBUG: Response s3/ListObjects Details:
---[ RESPONSE ]--------------------------------------
HTTP/1.1 200 OK
Transfer-Encoding: chunked
Content-Type: application/xml
Date: Thu, 24 Dec 2020 17:39:04 GMT
INFO[5:49PM]: incoming request  http-method=GET http-path=/readyz http-status=200 request-id=791e33ca-b6c2-4f5b-9da3-19c1b5672b87
ERROR[5:49PM]: signal: killed:  http-method=GET http-path=/google.golang.org/api/@v/v0.15.1-0.20200106000736-b8fc810ca6b5.mod kind=Internal Server Error module= operation=download.VersionModuleHandler ops=[download.VersionModuleHandler pool.GoMod protocol.GoMod protocol.processDownload stash.Pool stasher.Stash stasher.fetchModule goGetFetcher.Fetch module.downloadModule] request-id=a7fffc12-d276-403e-87b6-5f6f9f4f197e version=
INFO[5:49PM]: incoming request  http-method=GET http-path=/google.golang.org/api/@v/v0.15.1-0.20200106000736-b8fc810ca6b5.mod http-status=500 request-id=a7fffc12-d276-403e-87b6-5f6f9f4f197e

It looks like the module was downloaded into the s3 bucket but Athens could not fetch it during builds.

bnrjee commented 3 years ago

@arschles, would it be possible for you to look into it?

marwan-at-work commented 3 years ago

@bnrjee sorry for the delayed response. If you look at the ops field in the signal-killed log line, it looks like it failed when Athens was doing go mod download which at this point doesn't try to upload to S3 at all (even though it used S3 to check if the object exists in the first place already and that obviously hasn't failed, otherwise there would have been no go mod download)

My guess is that it might be a network issue inside your env.

Therefore, can you check that your Athens env can reach the internet? You can try doing a go mod download yourself from within your Athens instance and see what errors you get.

bnrjee commented 3 years ago

@marwan-at-work sorry for the late reply. Athens service can reach internet. We build bunch of other projects with athens and only these 2 fail. Other repos that we build with athens are
1> kubernetes/release 2> containernetworking/plugins 3> coredns/coredns 4> etcd-io/etcd 5> kubernetes-csi/external-attacher 6> kubernetes-csi/external-resizer 7> kubernetes-csi/livenessprobe 8> kubernetes-csi/node-driver-registrar 9> kubernetes-sigs/aws-iam-authenticator 10> kubernetes-sigs/metrics-server Athens works fine with these 10 repos.

DGollings commented 2 years ago

Have same/similar issue, can't download google.golang.org/api

Logs:

ERROR[2:10PM]: signal: killed:  http-method=GET http-path=/google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.mod kind=Internal Server Error module= operation=download.VersionModuleHandler ops=[download.VersionModuleHandler pool.GoMod protocol.GoMod protocol.processDownload stash.Pool stasher.Stash stasher.fetchModule goGetFetcher.Fetch module.downloadModule] request-id=7e7ddfb8-32bd-4b4e-86f3-17cd9e30c0fd version=

Manual curl

curl http:///google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.mod
= <a href="https://pkg.go.dev/google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.mod">Found</a>.

whilst using Athens Proxy

curl http://192.168.0.115:3000/google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.mod

hangs EDIT: eventually it prints out

go: github.com/golang-migrate/migrate/v4@v4.15.1 requires
    github.com/dhui/dktest@v0.3.7 requires
    github.com/containerd/containerd@v1.5.7 requires
    github.com/containerd/aufs@v1.0.0 requires
    github.com/containerd/containerd@v1.5.0-beta.3 requires
    github.com/Microsoft/hcsshim@v0.8.15 requires
    github.com/containerd/containerd@v1.5.0-beta.1 requires
    github.com/Microsoft/hcsshim/test@v0.0.0-20201218223536-d3e5debf77da requires
    github.com/docker/distribution@v0.0.0-20190905152932-14b96e55d84c requires
    google.golang.org/api@v0.0.0-20160322025152-9bf6e6e569ff: reading http://192.168.0.115:3000/google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.mod: 500 Internal Server Error
Done "go build -o /layers/google.go.build/bin/main ./api/shipmentp..." (9m36.788397781s)
Failure: (ID: fcf40e0a) go: github.com/golang-migrate/migrate/v4@v4.15.1 requires
    github.com/dhui/dktest@v0.3.7 requires
    github.com/containerd/containerd@v1.5.7 requires
    github.com/containerd/aufs@v1.0.0 requires
    github.com/containerd/containerd@v1.5.0-beta.3 requires
    github.com/Microsoft/hcsshim@v0.8.15 requires
    github.com/containerd/containerd@v1.5.0-beta.1 requires
    github.com/Microsoft/hcsshim/test@v0.0.0-20201218223536-d3e5debf77da requires
    github.com/docker/distribution@v0.0.0-20190905152932-14b96e55d84c requires
    google.golang.org/api@v0.0.0-20160322025152-9bf6e6e569ff: reading http://192.168.0.115:3000/google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.mod: 500 Internal Server Error

After switching to a different proxy I saw this:

goproxy.io: 682.108s 200 /google.golang.org/api/@v/v0.14.0.mod
goproxy.io: 726.829s 200 /google.golang.org/api/@v/v0.14.0.mod
goproxy.io: 701.686s 200 /google.golang.org/api/@v/v0.19.0.mod
goproxy.io: 690.539s 200 /google.golang.org/api/@v/v0.19.0.mod
goproxy.io: 652.935s 200 /google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.mod
goproxy.io: 714.658s 200 /google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.mod
goproxy.io: 652.590s 200 /google.golang.org/api/@v/v0.41.0.mod
goproxy.io: 698.337s 200 /google.golang.org/api/@v/v0.41.0.mod

aka, takes forever, maybe its an Athens internal timeout?

prosnekov commented 2 years ago

The same thing with the same module

athens          | DEBUG[12:34PM]: saving google.golang.org/api@v0.0.0-20160322025152-9bf6e6e569ff to storage... http-method=GET http-path=/google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.info request-id=e81033fe-df78-48b3-8d83-90ccf29021e5
athens          | ERROR[12:44PM]: signal: killed:   http-method=GET http-path=/google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.info kind=Internal Server Error module=google.golang.org/api operation=download.InfoHandler ops=[download.InfoHandler pool.Info protocol.Info protocol.processDownload stash.Pool stasher.Stash stasher.fetchModule goGetFetcher.Fetch module.downloadModule] request-id=e81033fe-df78-48b3-8d83-90ccf29021e5 version=v0.0.0-20160322025152-9bf6e6e569ff
athens          | INFO[12:44PM]: incoming request   http-method=GET http-path=/google.golang.org/api/@v/v0.0.0-20160322025152-9bf6e6e569ff.info http-status=500 request-id=e81033fe-df78-48b3-8d83-90ccf29021e5

We are using athens for a lot of modules but this is the only one which fails. And I agree that it looks like some kind of internal timeout.

+++ update +++ Solved by adding more CPU cores to athens VM.

buaafanrui commented 1 year ago

I have the same error for module google.golang.org/api@v0.0.0-20180910000450-7ca32eb868bf and I found two solutions to solve it.

  1. Use gopath cache. First, unset GOPROXY and run go get google.golang.org/api@v0.0.0-20180910000450-7ca32eb868bf command. This will download the module to your GOPATH. Then you can open GOPATH/pkg/mod/cache/download/google.golang.org/api/@v directory, which you could find three files: VERSION.mod, VERSION.info and VERSION.zip. Copy these files to ATHENS_DISK_STORAGE_ROOT/google.golang.org/api directory and rename them: VERSION.mod => go.mod VERSION.info => VERSION.info VERSION.zip => source.zip

  2. Use go module replace. Download google.golang.org/api@v0.0.0-20180910000450-7ca32eb868bf manully and add replace google.golang.org/api v0.0.0-20180910000450-7ca32eb868bf =>MODULE_PATH.

pboguslawski commented 2 months ago

Similar issue here:

2024-05-17 10:55:15 [...] DEBUG[10:55AM]: saving google.golang.org/api@v0.162.0 to storage...        http-method=GET http-path=/google.golang.org/api/@v/v0.162.0.zip [...]
2024-05-17 11:05:15 [...] ERROR[11:05AM]: signal: killed:    http-method=GET http-path=/google.golang.org/api/@v/v0.162.0.zip kind=Internal Server Error module= operation=download.ZipHandler ops=[download.ZipHandler pool.Zip protocol.Zip protocol.processDownload stash.Pool stasher.Stash stasher.fetchModule goGetFetcher.Fetch module.downloadModule] [...] version= 
2024-05-17 11:05:15 [...] INFO[11:05AM]: incoming request    http-method=GET http-path=/google.golang.org/api/@v/v0.162.0.zip http-status=500 [...]

Looks like go mod download is being killed after hardcoded 10 min timeout.

10 mins may be too low for larger repos on slower links/cpus so please increase it to say 60 mins or better make is configurable.

matt0x6F commented 2 months ago

@pboguslawski I think we can make that configurable