You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
I have a service that uses the httputil ReverseProxy as a load balancer, proxying requests to upstream services. My service averages ~10k requests per second, nearly all of which are streams. The streams are short lived - The P95 stream duration (the duration of time that a finished stream was alive) is 400ms.
I upgraded the x/net version from v0.0.0-20210929193557-e81a3d93ecf6 to v0.0.0-20220531201128-c960675eff93. I confirmed that the change directly after the old version, http2: refactor request write flow, is the first version that introduces the following symptoms.
What did you expect to see?
No noticeable behavior change to my service.
What did you see instead?
My service's number of currently open streams began growing unbounded. When healthy, my service has ~60 concurrent streams - With the upgrade, within 3 minutes it had reached 300k open streams and was continuing to grow.
2022/06/03 01:37:59 httputil: ReverseProxy read error during body copy: stream error: stream ID 1403; CANCEL
From the pprof:
I do not set a custom ReverseProxy ErrorLogger. My theory is that due to the cleanupWriteRequest introduced in the transport.go change, a CANCELed stream will now cause http2's Transport to return an error in RoundTrip, which is then consumed by ReverseProxy. ReverseProxy attempts to log each instance of this. Since the service has a high workload (rate of stream requests proxied), the logger falls behind and causes the buildup of concurrent streams.
changed the title
x/net,httputil: ReverseProxy attempts to log each http2 stream cancellation, causing concurrent streams to grow unbounded due to logger buildup
x/net,net/http/httputil: ReverseProxy attempts to log each http2 stream cancellation, causing concurrent streams to grow unbounded due to logger buildup
Jun 6, 2022