Quarantine ServerReset_BeforeRequestBody_ClientBodyThrows

[sebastienros]

Failing Test(s)

Interop.FunctionalTests.HttpClientHttp2InteropTests.ServerReset_BeforeRequestBody_ClientBodyThrows(scheme: "http")

Error Message

Assert.Throws() Failure
Expected: typeof(System.Net.Http.HttpProtocolException)
Actual:   typeof(System.TimeoutException): The operation has timed out.

Stacktrace

[0.002s] TestLifetime Information: Starting test ServerReset_BeforeRequestBody_ClientBodyThrows-http at 2023-02-16T19:30:12
[0.004s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting starting
[0.006s] Microsoft.Hosting.Lifetime Information: Now listening on: http://127.0.0.1:62225
[0.006s] Microsoft.AspNetCore.Hosting.Diagnostics Debug: Loaded hosting startup assembly Interop.FunctionalTests
[0.006s] Microsoft.Hosting.Lifetime Information: Application started. Press Ctrl+C to shut down.
[0.006s] Microsoft.Hosting.Lifetime Information: Hosting environment: Production
[0.006s] Microsoft.Hosting.Lifetime Information: Content root path: /private/tmp/helix/working/95B607EB/w/B4DB094B/e/
[0.006s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting started
[0.008s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMOGAGQC1994" accepted.
[0.008s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMOGAGQC1994" started.
[0.009s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" sending SETTINGS frame for stream ID 0 with length 24 and flags NONE.
[0.009s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" sending WINDOW_UPDATE frame for stream ID 0 with length 4 and flags 0x0.
[0.010s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" received SETTINGS frame for stream ID 0 with length 12 and flags NONE.
[0.011s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" sending SETTINGS frame for stream ID 0 with length 0 and flags ACK.
[0.011s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" received WINDOW_UPDATE frame for stream ID 0 with length 4 and flags 0x0.
[0.011s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" received HEADERS frame for stream ID 1 with length 35 and flags END_HEADERS.
[0.011s] Microsoft.AspNetCore.Hosting.Diagnostics Information: Request starting HTTP/2 POST http://127.0.0.1:62225/ - - -
[0.011s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" sending HEADERS frame for stream ID 1 with length 53 and flags END_HEADERS.
[0.014s] Microsoft.AspNetCore.Server.Kestrel.Http2 Debug: Trace id "0HMOGAGQC1994:00000001": HTTP/2 stream error "CANCEL". A Reset is being sent to the stream.
Microsoft.AspNetCore.Connections.ConnectionAbortedException: The HTTP/2 stream was reset by the application with error code CANCEL.
[0.015s] Microsoft.AspNetCore.Hosting.Diagnostics Information: Request finished HTTP/2 POST http://127.0.0.1:62225/ - 200 - text/plain 3.8277ms
[0.015s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" sending RST_STREAM frame for stream ID 1 with length 4 and flags 0x0.
[0.015s] Microsoft.AspNetCore.Server.Kestrel Information: Connection id "0HMOGAGQC1994", Request id "0HMOGAGQC1994:00000001": the application completed without reading the entire request body.
[0.016s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" received SETTINGS frame for stream ID 0 with length 0 and flags ACK.
[0.017s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" received PING frame for stream ID 0 with length 8 and flags NONE.
[0.017s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMOGAGQC1994" sending PING frame for stream ID 0 with length 8 and flags ACK.
[30.040s] Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets Debug: Connection id "0HMOGAGQC1994" received FIN.
[30.040s] Microsoft.AspNetCore.Server.Kestrel.Http2 Debug: Connection id "0HMOGAGQC1994" is closed. The last processed stream ID was 1.
[30.040s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Some connections failed to close gracefully during server shutdown.
[30.040s] Microsoft.AspNetCore.Server.Kestrel.Http2 Debug: The connection queue processing loop for 0HMOGAGQC1994 completed.
[30.040s] Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets Debug: Connection id "0HMOGAGQC1994" sending FIN because: "The client closed the connection."
[30.041s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMOGAGQC1994" stopped.
[30.042s] Interop.FunctionalTests.HttpClientHttp2InteropTests Error: Test threw an exception.

Logs

Build

https://dev.azure.com/dnceng-public/public/_build/results?buildId=174755&view=logs&j=3f6d4e0f-1b71-56b5-361e-d95b6e6da15a&t=e4ee6667-9b0a-5a6e-4e24-bcba939f2af2

[dougbu]

Is the fix here as simple as increasing a timeout setting somewhere❔

[sebastienros]

@dougbu I don't think so because we have seen it working very quickly, but when it failed it was after the default 30s max. We saw at least it fail twice in the last two days.