grpc-go
grpc-go copied to clipboard
Flaky test: Test/HTTPHeaderFrameErrorHandlingMoreThanTwoHeaders
https://github.com/grpc/grpc-go/runs/4476382916?check_suite_focus=true
2021/12/09 21:24:47 http: TLS handshake error from 127.0.0.1:60600: write tcp 127.0.0.1:41773->127.0.0.1:60600: use of closed network connection
2021/12/09 21:25:56 http: TLS handshake error from 127.0.0.1:49168: write tcp 127.0.0.1:43987->127.0.0.1:49168: use of closed network connection
2021/12/09 21:26:38 http: TLS handshake error from 127.0.0.1:45668: write tcp 127.0.0.1:46697->127.0.0.1:45668: use of closed network connection
2021/12/09 21:27:26 http: TLS handshake error from 127.0.0.1:58884: write tcp 127.0.0.1:35977->127.0.0.1:58884: use of closed network connection
2021/12/09 21:27:39 http: TLS handshake error from 127.0.0.1:45448: write tcp 127.0.0.1:42771->127.0.0.1:45448: use of closed network connection
--- FAIL: Test (85.00s)
--- FAIL: Test/HTTPHeaderFrameErrorHandlingMoreThanTwoHeaders (0.05s)
tlogger.go:116: INFO clientconn.go:175 [core] Channel Created (t=+227.598µs)
tlogger.go:116: INFO clientconn.go:1623 [core] original dial target is: "127.0.0.1:33353" (t=+271.998µs)
tlogger.go:116: INFO clientconn.go:1628 [core] dial target "127.0.0.1:33353" parse failed: parse "127.0.0.1:33353": first path segment in URL cannot contain colon (t=+296.598µs)
tlogger.go:116: INFO clientconn.go:1643 [core] fallback to scheme "passthrough" (t=+315.798µs)
tlogger.go:116: INFO clientconn.go:1651 [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:127.0.0.1:33353 URL:{Scheme:passthrough Opaque: User: Host: Path:/127.0.0.1:33353 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}} (t=+343.298µs)
tlogger.go:116: INFO clientconn.go:262 [core] Channel authority set to "127.0.0.1:33353" (t=+361.197µs)
tlogger.go:116: INFO resolver_conn_wrapper.go:100 [core] ccResolverWrapper: sending update to cc: {[{127.0.0.1:33353 <nil> <nil> 0 <nil>}] <nil> <nil>} (t=+383.597µs)
tlogger.go:116: INFO resolver_conn_wrapper.go:183 [core] Resolver state updated: {Addresses:[{Addr:127.0.0.1:33353 ServerName: Attributes:<nil> BalancerAttributes:<nil> Type:0 Metadata:<nil>}] ServiceConfig:<nil> Attributes:<nil>} (resolver returned new addresses) (t=+405.297µs)
tlogger.go:116: INFO clientconn.go:712 [core] ClientConn switching balancer to "pick_first" (t=+420.397µs)
tlogger.go:116: INFO clientconn.go:732 [core] Channel switches to new LB policy "pick_first" (t=+437.997µs)
tlogger.go:116: INFO clientconn.go:773 [core] Subchannel Created (t=+480.896µs)
tlogger.go:116: INFO clientconn.go:773 [core] Subchannel(id:1224) created (t=+493.796µs)
tlogger.go:116: INFO picker_wrapper.go:161 [core] blockingPicker: the picked transport is not ready, loop back to repick (t=+527.296µs)
tlogger.go:116: INFO clientconn.go:1143 [core] Subchannel Connectivity change to CONNECTING (t=+549.396µs)
tlogger.go:116: INFO clientconn.go:1254 [core] Subchannel picks a new address "127.0.0.1:33353" to connect (t=+571.896µs)
tlogger.go:116: INFO clientconn.go:417 [core] Channel Connectivity change to CONNECTING (t=+973.793µs)
tlogger.go:116: INFO clientconn.go:1143 [core] Subchannel Connectivity change to READY (t=+1.124492ms)
tlogger.go:116: INFO clientconn.go:417 [core] Channel Connectivity change to READY (t=+1.155391ms)
tlogger.go:116: INFO clientconn.go:417 [core] Channel Connectivity change to SHUTDOWN (t=+1.475389ms)
tlogger.go:116: INFO clientconn.go:1143 [core] Subchannel Connectivity change to SHUTDOWN (t=+1.496689ms)
tlogger.go:116: INFO clientconn.go:1501 [core] Subchannel Deleted (t=+1.510889ms)
tlogger.go:116: INFO clientconn.go:1501 [core] Subchanel(id:1224) deleted (t=+1.522489ms)
tlogger.go:116: INFO clientconn.go:1099 [core] Channel Deleted (t=+1.535888ms)
tlogger.go:116: INFO types.go:68 [channelz] attempt to delete child with id 1224 from a parent (id=1223) that doesn't currently exist (t=+4.384067ms)
tlogger.go:116: INFO types.go:68 [channelz] attempt to delete child with id 1224 from a parent (id=1223) that doesn't currently exist (t=+4.422666ms)
end2end_test.go:7418: Error at server-side while reading frame. Err: read tcp 127.0.0.1:33353->127.0.0.1:47896: read: connection reset by peer
FAIL
One more: https://github.com/grpc/grpc-go/runs/4538453130?check_suite_focus=true
Not flaking of late.
https://github.com/grpc/grpc-go/runs/7638640797?check_suite_focus=true
https://github.com/grpc/grpc-go/actions/runs/3276440555/jobs/5392494447
Fails 2/10k on google3
The underlying issue seems to be the same as the one causing Test/HTTPHeaderFrameErrorHandlingNormalTrailer
Sounds good; let's close this one then.