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.
Comment From: gabyhelp
Related Issues and Documentation
- x/net/http: PROTOCOL_ERROR with HTTP2 #29125 (closed)
- net/http: frequent HTTP2 INTERNAL_ERROR errors during module zip download since 2021-10-06 #51323
- x/net/http2: support http2 proxy connections #26479
- proxy.golang.org: invalid pseudo-version: does not match version-control timestamp #33530 (closed)
- x/net/http2: server cannot process Trailer frames correctly after RST_STREAM #58286
- net/http/httputil: ReverseProxy fails to proxy h2c #33452 (closed)
- proxy.golang.org 403 forbidden much like #48107 #62448
- x/net/http2: downloading files from kernel.org results in PROTOCOL_ERROR stream error #19035 (closed)
- x/net/http2/hpack: "id (106) \<= evictCount (117)" panic in headerFieldTable.idToIndex #69316
- golang.org/x/textaffected/package: #63998 (closed)
(Emoji vote if this was helpful or unhelpful; more detailed feedback welcome in this discussion.)
Comment From: bradfitz
51323 smells similar, but different error codes.
Comment From: mvdan
We have seen four of these in the past week too.
Comment From: mvdan
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
Comment From: deyigifts
Same here, found 3-rd party mirror works.
go env -w GOPROXY=https://<mirror site>,direct
Comment From: cagedmantis
Comment From: neild
"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).
Comment From: Emily-ODonovan
Another one here, I'm currently working around it by setting
ENV GODEBUG=http2client=0
ENV GOPROXY=https://proxy.golang.org
Comment From: neild
It'd be very helpful if anyone could get GODEBUG=http2debug=1 output for a time period covering a failure.
Comment From: prattmic
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)?
Comment From: jpluscplusm
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.
Comment From: prattmic
It turns out we see this in Go's CI as well, which is not GH Actions.
Comment From: kevindejong
I experience this on my laptop.
@neild I have attached a log with GODEBUG=http2debug=1
enabled.
protocolerror.txt
Comment From: findleyr
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.
Comment From: bradfitz
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
Comment From: neild
GFE rollout should be completed now, no further errors expected.