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

proxy.golang.org, cmd/go, net/http: http2 PROTOCOL_ERRORS from the proxy #69544

Closed
bradfitz opened this issue Sep 20, 2024 · 16 comments
Closed
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. proxy.golang.org Soon This needs action soon. (recent regressions, service outages, unusual time-sensitive situations) Tools This label describes issues relating to any tools in the x/tools repository.
Milestone

Comments

@bradfitz
Copy link
Contributor

bradfitz commented Sep 20, 2024

Go version

go1.23.1 Linux (on GitHub Actions CI runs)

What did you do?

A ton of our GitHub CI jobs started failing today with http2 protocol errors from proxy.golang.org while fetching modules.

e.g.

go: downloading golang.org/x/sys v0.22.0
go: downloading github.com/google/uuid v1.6.0
go: downloading golang.org/x/mod v0.19.0
go: downloading go4.org/mem v0.0.0-20220726221520-4f986261bf13
protocol error: received DATA before a HEADERS frame
go: downloading golang.org/x/crypto v0.25.0
go: downloading github.com/go-json-experiment/json v0.0.0-20231102232822-2e[55](https://github.com/tailscale/tailscale/actions/runs/10952031566/job/30410038652?pr=13528#step:3:56)bd4e08b0
types/views/views.go:18:2: go4.org/mem@v0.0.0-20220726221520-4f986261bf13: Get "https://proxy.golang.org/go4.org/mem/@v/v0.0.0-20220726221520-4f986261bf13.zip": stream error: stream ID 7; PROTOCOL_ERROR

and

go: downloading golang.org/x/sys v0.22.0
go: downloading github.com/google/uuid v1.6.0
go: downloading golang.org/x/mod v0.19.0
go: downloading go4.org/mem v0.0.0-20220726221[52](https://github.com/tailscale/tailscale/actions/runs/10952031566/job/30410034814?pr=13528#step:7:53)0-4f986261bf13
protocol error: received DATA before a HEADERS frame
go: downloading golang.org/x/crypto v0.25.0
go: downloading github.com/go-json-experiment/json v0.0.0-20231102232822-2e[55](https://github.com/tailscale/tailscale/actions/runs/10952031566/job/30410034814?pr=13528#step:7:56)bd4e08b0
version/mkversion/mkversion.go:20:2: github.com/google/uuid@v1.6.0: Get "https://proxy.golang.org/github.com/google/uuid/@v/v1.6.0.mod": stream error: stream ID 9; PROTOCOL_ERROR

and

go: downloading golang.org/x/sys v0.22.0
go: downloading github.com/google/uuid v1.6.0
go: downloading golang.org/x/mod v0.19.0
protocol error: received DATA before a HEADERS frame
go: downloading github.com/go-json-experiment/json v0.0.0-20231102232822-2e[55](https://github.com/tailscale/tailscale/actions/runs/10952031566/job/30410038180?pr=13528#step:4:56)bd4e08b0
go: downloading go4.org/mem v0.0.0-20220726221520-4f986261bf13
go: downloading golang.org/x/crypto v0.25.0
version/mkversion/mkversion.go:20:2: github.com/google/uuid@v1.6.0: Get "https://proxy.golang.org/github.com/google/uuid/@v/v1.6.0.zip": stream error: stream ID 3; PROTOCOL_ERROR

and

go: downloading golang.org/x/sys v0.22.0
go: downloading github.com/google/uuid v1.6.0
go: downloading golang.org/x/mod v0.19.0
go: downloading go4.org/mem v0.0.0-20220726221[52](https://github.com/tailscale/tailscale/actions/runs/10952031566/job/30410039037?pr=13528#step:3:53)0-4f986261bf13
protocol error: received DATA before a HEADERS frame
go: downloading golang.org/x/crypto v0.25.0
go: downloading github.com/go-json-experiment/json v0.0.0-20231102232822-2e[55](https://github.com/tailscale/tailscale/actions/runs/10952031566/job/30410039037?pr=13528#step:3:56)bd4e08b0
types/views/views.go:18:2: go4.org/mem@v0.0.0-20220726221520-4f986261bf13: Get "https://proxy.golang.org/go4.org/mem/@v/v0.0.0-20220726221520-4f986261bf13.zip": stream error: stream ID 7; PROTOCOL_ERROR

and a dozen others, all similar.

This doesn't correspond to any change on our side.

Is this a Google HTTP frontend push gone bad? Is it now strict about something that it wasn't before and either its check is wrong or Go's HTTP/2 client is buggy in ways we'd never noticed previously?

/cc @neild

What did you see happen?

The cmd/go tool is saying, during module fetches:

protocol error: received DATA before a HEADERS frame
...
Get "https://proxy.golang.org/go4.org/mem/@v/v0.0.0-20220726221520-4f986261bf13.zip": stream error: stream ID 7; PROTOCOL_ERROR

... and then failing.

@bradfitz
Copy link
Contributor Author

#51323 smells similar, but different error codes.

@mvdan
Copy link
Member

mvdan commented Sep 20, 2024

We have seen four of these in the past week too.

@mvdan
Copy link
Member

mvdan commented Sep 20, 2024

On September 18th at around 08:20 UTC:

github.com/cockroachdb/apd/v3: github.com/cockroachdb/apd/v3@v3.2.1: Get "https://proxy.golang.org/github.com/cockroachdb/apd/v3/@v/v3.2.1.zip": stream error: stream ID 3; PROTOCOL_ERROR

September 19th around 15:00 UTC:

github.com/go-quicktest/qt: github.com/go-quicktest/qt@v1.101.0: Get "https://proxy.golang.org/github.com/go-quicktest/qt/@v/v1.101.0.zip": stream error: stream ID 5; PROTOCOL_ERROR

September 20th around 07:40 UTC:

go: k8s.io/api/apps/v1@v0.29.3: k8s.io/api/apps@v0.29.3: Get "https://proxy.golang.org/k8s.io/api/apps/@v/v0.29.3.info": stream error: stream ID 5; PROTOCOL_ERROR

September 20th around 09:40 UTC:

golang.org/x/sys/unix: golang.org/x/sys@v0.21.0: Get "https://proxy.golang.org/golang.org/x/sys/@v/v0.21.0.zip": stream error: stream ID 137; PROTOCOL_ERROR

Other failures around the same days which we almost never encounter:

September 19th around 16:00 UTC:

go: cuelang.org/go/internal/ci/checks@v0.11.0-0.dev.0.20240903133435-46fb300df650: cuelang.org/go@v0.11.0-0.dev.0.20240903133435-46fb300df650: verifying module: cuelang.org/go@v0.11.0-0.dev.0.20240903133435-46fb300df650: Get "https://sum.golang.org/lookup/cuelang.org/go@v0.11.0-0.dev.0.20240903133435-46fb300df650": net/http: TLS handshake timeout

September 20th around 11:40 UTC:

go: cuelang.org/go@master: cuelang.org/go@v0.11.0-alpha.1.0.20240920112956-687464eb1846: verifying module: cuelang.org/go@v0.11.0-alpha.1.0.20240920112956-687464eb1846: reading https://sum.golang.org/lookup/cuelang.org/go@v0.11.0-alpha.1.0.20240920112956-687464eb1846: 500 Internal Server Error

@deyigifts
Copy link

Same here, found 3-rd party mirror works.
go env -w GOPROXY=https://<mirror site>,direct

@cagedmantis cagedmantis changed the title cmd/go, net/http: http2 PROTOCOL_ERRORS from proxy.golang.org proxy.golang.org, cmd/go, net/http: http2 PROTOCOL_ERRORS from the proxy Sep 20, 2024
@cagedmantis cagedmantis added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Tools This label describes issues relating to any tools in the x/tools repository. labels Sep 20, 2024
@cagedmantis cagedmantis added this to the Unreleased milestone Sep 20, 2024
@cagedmantis
Copy link
Contributor

cc @golang/tools-team

@neild
Copy link
Contributor

neild commented Sep 20, 2024

"received DATA before a HEADERS frame" is the Go HTTP/2 client, and it's complaining about exactly what it sounds like. Either the server is committing a protocol violation, or something is going on that I don't understand (always possible).

@Emily-ODonovan
Copy link

Another one here, I'm currently working around it by setting

ENV GODEBUG=http2client=0
ENV GOPROXY=https://proxy.golang.org

@dmitshur dmitshur added the Soon This needs action soon. (recent regressions, service outages, unusual time-sensitive situations) label Sep 20, 2024
@neild
Copy link
Contributor

neild commented Sep 20, 2024

It'd be very helpful if anyone could get GODEBUG=http2debug=1 output for a time period covering a failure.

cueckoo pushed a commit to cue-lang/cuelang.org-trybot that referenced this issue Sep 20, 2024
This temporarily adds a GODEBUG flag (as requested at
golang/go#69544 (comment)) to a
CI step whose output we don't much care about spamming, to help debug a
Go proxy issue that's started to affect us sporadically.

Signed-off-by: Jonathan Matthews <github@hello.jonathanmatthews.com>
Change-Id: I030b06b3991b85da352d2a8bd98e0b0693831267
Dispatch-Trailer: {"type":"trybot","CL":1201575,"patchset":2,"ref":"refs/changes/75/1201575/2","targetBranch":"master"}
@prattmic
Copy link
Member

Brad mentioned that they saw this on GitHub Actions. Can others report if you also saw this on GitHub Actions, or on some other infrastructure (such as a personal computer or other CI)?

@jpluscplusm
Copy link

Can others report if you also saw this on GitHub Actions, or on some other infrastructure (such as a personal computer or other CI)?

I believe I can speak for @mvdan: we have seen this only from inside GitHub Actions.

@prattmic
Copy link
Member

It turns out we see this in Go's CI as well, which is not GH Actions.

@kevindejong
Copy link

kevindejong commented Sep 20, 2024

I experience this on my laptop.
@neild I have attached a log with GODEBUG=http2debug=1 enabled.
protocolerror.txt

@findleyr
Copy link
Contributor

findleyr commented Sep 20, 2024

Thanks everyone for your help. @neild was able to reproduce the problem reliably, and the cause has been found in a recent rollout to Google frontends. The rollback is proceeding.

@bradfitz
Copy link
Contributor Author

I was worried that Go's http2 client was getting confused, but this server response does look wrong, with the DATA for stream=451 coming before its HEADERS..... (from @kevindejong's attachment above)

http2: Transport received DATA flags=END_STREAM stream=451 len=8829 data="PK\x03\x04\x14\x00\b\x00\b\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00b\x00\x00\x00github.com/GoogleCloudPlatform/opentelemetry-operations-go/internal/resourcemapping@v0.44.0/go.modt\xcf\xc1N\xc4 \x10\xc6\xf1\xb3<\x05G\xf7P\x18`\xbb\x9b\x9e=x\xf5\x15(\x9d\"\tep\n\x9b\xf8\xf6\xa6z\xaa\xd1\xf3|\xf9\xfd3\x1b-=\xa3\x8c\xa9\xbd\xf7Y\x05\xda\xf4+Q\xcc\xf8\x92\xa9/oٷ\x95x\xd3T\xb14̸a\xe3ρ*\xb2o\x89\xca>Dҩ4\xe4\xe2\xb3fܩs\xc0\xcdךJ\x14\"\x924ʂ\x10\x8c\x1f=1\xcag\xf1\x14I\x9d0\x95HS\xc3,\x1fF\x99I\xc1\xb1" (8573 bytes omitted)
protocol error: received DATA before a HEADERS frame
http2: Transport received HEADERS flags=END_HEADERS stream=427 len=147
http2: Transport received HEADERS flags=END_HEADERS stream=449 len=146
RoundTrip failure: stream error: stream ID 451; PROTOCOL_ERROR
http2: Transport received PING len=8 ping="\x00\x00\x00\x00\x00\x00\x03$"
http2: Transport received HEADERS flags=END_HEADERS stream=451 len=118

@neild
Copy link
Contributor

neild commented Sep 21, 2024

GFE rollout should be completed now, no further errors expected.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. proxy.golang.org Soon This needs action soon. (recent regressions, service outages, unusual time-sensitive situations) Tools This label describes issues relating to any tools in the x/tools repository.
Projects
None yet
Development

No branches or pull requests