Flaky RunIndividualTestCase(http2_6.9.1_2) test

[BrennanConroy]

The test is skipped because it's part of a theory of a couple hundred tests and can't be quarantined.

Logs

[0.001s] [TestLifetime] [Information] Starting test RunIndividualTestCase-http2_6.9.1_2,_HTTPS_False,_Sends_multiple_WINDOW_UPDATE_frames_increasing_the_flow_control_window_to_above_2^31-1 at 2021-02-20T01:01:58
[0.001s] [Microsoft.Extensions.Hosting.Internal.Host] [Debug] Hosting starting
[0.018s] [Microsoft.Hosting.Lifetime] [Information] Now listening on: http://127.0.0.1:50070
[0.018s] [Microsoft.AspNetCore.Hosting.Diagnostics] [Debug] Loaded hosting startup assembly Interop.FunctionalTests
[0.018s] [Microsoft.Hosting.Lifetime] [Information] Application started. Press Ctrl+C to shut down.
[0.018s] [Microsoft.Hosting.Lifetime] [Information] Hosting environment: Production
[0.018s] [Microsoft.Hosting.Lifetime] [Information] Content root path: C:\h\w\A0F508EF\w\A971098F\e\
[0.018s] [Microsoft.Extensions.Hosting.Internal.Host] [Debug] Hosting started
[0.037s] [Interop.FunctionalTests.H2SpecTests] [Debug] Hypertext Transfer Protocol Version 2 (HTTP/2)
[0.037s] [Interop.FunctionalTests.H2SpecTests] [Debug]   6. Frame Definitions
[0.037s] [Interop.FunctionalTests.H2SpecTests] [Debug]     6.9. WINDOW_UPDATE
[0.037s] [Interop.FunctionalTests.H2SpecTests] [Debug]       6.9.1. The Flow-Control Window
[0.037s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HM6L7CEVBL75" accepted.
[0.037s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HM6L7CEVBL75" started.
[0.037s] [Interop.FunctionalTests.H2SpecTests] [Debug]              [send] SETTINGS Frame (length:6, flags:0x00, stream_id:0)
[0.038s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "0HM6L7CEVBL75" sending SETTINGS frame for stream ID 0 with length 18 and flags NONE.
[0.038s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "0HM6L7CEVBL75" sending WINDOW_UPDATE frame for stream ID 0 with length 4 and flags 0x0.
[0.038s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "0HM6L7CEVBL75" received SETTINGS frame for stream ID 0 with length 6 and flags NONE.
[0.038s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "0HM6L7CEVBL75" sending SETTINGS frame for stream ID 0 with length 0 and flags ACK.
[0.038s] [Interop.FunctionalTests.H2SpecTests] [Debug]              [recv] SETTINGS Frame (length:18, flags:0x00, stream_id:0)
[0.038s] [Interop.FunctionalTests.H2SpecTests] [Debug]              [send] SETTINGS Frame (length:0, flags:0x01, stream_id:0)
[0.038s] [Interop.FunctionalTests.H2SpecTests] [Debug]              [recv] WINDOW_UPDATE Frame (length:4, flags:0x00, stream_id:0)
[0.038s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "0HM6L7CEVBL75" received SETTINGS frame for stream ID 0 with length 0 and flags ACK.
[0.038s] [Interop.FunctionalTests.H2SpecTests] [Debug]              [recv] SETTINGS Frame (length:0, flags:0x01, stream_id:0)
[0.038s] [Interop.FunctionalTests.H2SpecTests] [Debug]              [send] WINDOW_UPDATE Frame (length:4, flags:0x00, stream_id:0)
[0.038s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "0HM6L7CEVBL75" received WINDOW_UPDATE frame for stream ID 0 with length 4 and flags 0x0.
[0.039s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HM6L7CEVBL75": HTTP/2 connection error.
Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.Http2ConnectionErrorException: HTTP/2 connection error (FLOW_CONTROL_ERROR): The client sent a WINDOW_UPDATE frame that caused a flow-control window to exceed the maximum size.
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.Http2Connection.ProcessWindowUpdateFrameAsync() in /_/src/Servers/Kestrel/Core/src/Internal/Http2/Http2Connection.cs:line 913
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.Http2Connection.ProcessFrameAsync[TContext](IHttpApplication`1 application, ReadOnlySequence`1& payload) in /_/src/Servers/Kestrel/Core/src/Internal/Http2/Http2Connection.cs:line 483
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.Http2Connection.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
[0.039s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HM6L7CEVBL75" is closed. The last processed stream ID was 0.
[0.039s] [Microsoft.AspNetCore.Server.Kestrel] [Verbose] Connection id "0HM6L7CEVBL75" sending GOAWAY frame for stream ID 0 with length 8 and flags 0x0.
[0.039s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HM6L7CEVBL75" stopped.
[0.039s] [Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets] [Debug] Connection id "0HM6L7CEVBL75" sending FIN because: "The Socket transport's send loop completed gracefully."
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]              [send] WINDOW_UPDATE Frame (length:4, flags:0x00, stream_id:0)
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]              [recv] Connection closed
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]         × 2: Sends multiple WINDOW_UPDATE frames increasing the flow control window to above 2^31-1
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]           -> The endpoint MUST sends a GOAWAY frame with a FLOW_CONTROL_ERROR code.
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]              Expected: GOAWAY Frame (Error Code: FLOW_CONTROL_ERROR)
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]                Actual: Connection closed
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug] Failures: 
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug] Hypertext Transfer Protocol Version 2 (HTTP/2)
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]   6. Frame Definitions
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]     6.9. WINDOW_UPDATE
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]       6.9.1. The Flow-Control Window
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]         × 2: Sends multiple WINDOW_UPDATE frames increasing the flow control window to above 2^31-1
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]           -> The endpoint MUST sends a GOAWAY frame with a FLOW_CONTROL_ERROR code.
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]              Expected: GOAWAY Frame (Error Code: FLOW_CONTROL_ERROR)
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug]                Actual: Connection closed
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug] Finished in 0.0030 seconds
[0.039s] [Interop.FunctionalTests.H2SpecTests] [Debug] 1 tests, 0 passed, 0 skipped, 1 failed
[0.043s] [Interop.FunctionalTests.H2SpecTests] [Debug] H2spec has exited.
[0.052s] [Interop.FunctionalTests.H2SpecTests] [Error] Test threw an exception.
System.Exception: Test failed: http2/6.9.1; 6.9.1. The Flow-Control Window
   at Interop.FunctionalTests.H2SpecCommands.RunTest(String testId, Int32 port, Boolean https, ILogger logger) in /_/src/Servers/Kestrel/test/Interop.FunctionalTests/H2SpecCommands.cs:line 280
   at Interop.FunctionalTests.H2SpecTests.RunIndividualTestCase(H2SpecTestCase testCase) in /_/src/Servers/Kestrel/test/Interop.FunctionalTests/H2SpecTests.cs:line 50
   at Xunit.Sdk.TestInvoker`1.<>c__DisplayClass48_1.<<InvokeTestMethodAsync>b__1>d.MoveNext() in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\TestInvoker.cs:line 264
--- End of stack trace from previous location ---
   at Xunit.Sdk.ExecutionTimer.AggregateAsync(Func`1 asyncAction) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\ExecutionTimer.cs:line 48
   at Xunit.Sdk.ExceptionAggregator.RunAsync(Func`1 code) in C:\Dev\xunit\xunit\src\xunit.core\Sdk\ExceptionAggregator.cs:line 90
[0.053s] [TestLifetime] [Information] Finished test RunIndividualTestCase-http2_6.9.1_2,_HTTPS_False,_Sends_multiple_WINDOW_UPDATE_frames_increasing_the_flow_control_window_to_above_2^31-1 in 0.0521824s

Build: https://dev.azure.com/dnceng/public/_build/results?buildId=1003834&view=ms.vss-test-web.build-test-results-tab&runId=31354936&resultId=108139&paneView=debug

[Tratcher]

Hmm, the server logged it was sending the GOAWAY, but the test complains the connection was closed before it was received. This could be a race on either end. We haven't updated h2spec in a long time, we should check if there have been fixes in this test scenario.

[ghost]

We've moved this issue to the Backlog milestone. This means that it is not going to be worked on for the coming release. We will reassess the backlog following the current release and consider this item at that time. To learn more about our issue management process and to have better expectation regarding different types of issues you can read our Triage Process.

[amcasey]

Highlighting the interesting bit

Hypertext Transfer Protocol Version 2 (HTTP/2)
  6. Frame Definitions
    6.9. WINDOW_UPDATE
      6.9.1. The Flow-Control Window
        × 2: Sends multiple WINDOW_UPDATE frames increasing the flow control window to above 2^31-1
          -> The endpoint MUST sends a GOAWAY frame with a FLOW_CONTROL_ERROR code.
             Expected: GOAWAY Frame (Error Code: FLOW_CONTROL_ERROR)
               Actual: Connection closed

[amcasey]

Whether the GOAWAY is sent appears to depend on whether TryClose succeeds (i.e. it won't happen if another thread has already closed the connection.

aspnetcore/src/Servers/Kestrel/Core/src/Internal/Http2/Http2Connection.cs

Line 446 in ffd5a38

if (TryClose())

[amcasey]

I don't see a second call to TryClose in local runs. There were huge changes in this area in 7.0, so this is probably moot.