[2.2] Fix race conditions in HTTP/2 tests (#3078)

test/Kestrel.InMemory.FunctionalTests/Http2/Http2ConnectionTests.cs

@@ -816,19 +816,15 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
 
             await SendDataAsync(1, _helloWorldBytes, endStream: false);
 
+            // There's a race where either of these messages could be logged, depending on if the stream cleanup has finished yet.
             await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(
                 ignoreNonGoAwayFrames: false,
                 expectedLastStreamId: 1,
                 expectedErrorCode: Http2ErrorCode.STREAM_CLOSED,
-                expectedErrorMessage: null);
+                expectedErrorMessage: new[] {
-
+                    CoreStrings.FormatHttp2ErrorStreamClosed(Http2FrameType.DATA, streamId: 1),
-            // There's a race where either of these messages could be logged, depending on if the stream cleanup has finished yet.
+                    CoreStrings.FormatHttp2ErrorStreamHalfClosedRemote(Http2FrameType.DATA, streamId: 1)
-            var closedMessage = CoreStrings.FormatHttp2ErrorStreamClosed(Http2FrameType.DATA, streamId: 1);
+                });
-            var halfClosedMessage = CoreStrings.FormatHttp2ErrorStreamHalfClosedRemote(Http2FrameType.DATA, streamId: 1);
-
-            var message = Assert.Single(TestApplicationErrorLogger.Messages, m => m.Exception is Http2ConnectionErrorException);
-            Assert.True(message.Exception.Message.IndexOf(closedMessage) >= 0
-                || message.Exception.Message.IndexOf(halfClosedMessage) >= 0);
         }
 
         [Fact]
@@ -1329,19 +1325,15 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
             // Try to re-use the stream ID (http://httpwg.org/specs/rfc7540.html#rfc.section.5.1.1)
             await StartStreamAsync(1, _browserRequestHeaders, endStream: true);
 
+            // There's a race where either of these messages could be logged, depending on if the stream cleanup has finished yet.
             await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(
                 ignoreNonGoAwayFrames: false,
                 expectedLastStreamId: 1,
                 expectedErrorCode: Http2ErrorCode.STREAM_CLOSED,
-                expectedErrorMessage: null);
+                expectedErrorMessage: new[] {
-
+                    CoreStrings.FormatHttp2ErrorStreamClosed(Http2FrameType.HEADERS, streamId: 1),
-            // There's a race where either of these messages could be logged, depending on if the stream cleanup has finished yet.
+                    CoreStrings.FormatHttp2ErrorStreamHalfClosedRemote(Http2FrameType.HEADERS, streamId: 1)
-            var closedMessage = CoreStrings.FormatHttp2ErrorStreamClosed(Http2FrameType.HEADERS, streamId: 1);
+                });
-            var halfClosedMessage = CoreStrings.FormatHttp2ErrorStreamHalfClosedRemote(Http2FrameType.HEADERS, streamId: 1);
-
-            var message = Assert.Single(TestApplicationErrorLogger.Messages, m => m.Exception is Http2ConnectionErrorException);
-            Assert.True(message.Exception.Message.IndexOf(closedMessage) >= 0
-                || message.Exception.Message.IndexOf(halfClosedMessage) >= 0);
         }
 
         [Fact]
@@ -3782,12 +3774,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
             // Logged without an exception.
             Assert.Contains(TestApplicationErrorLogger.Messages, m => m.Message.Contains("the application completed without reading the entire request body."));
 
-            // There's a race when the appfunc is exiting about how soon it unregisters the stream.
-            for (var i = 0; i < 10; i++)
-            {
-                await SendDataAsync(1, new byte[100], endStream: false);
-            }
-
             // These would be refused if the cool-down period had expired
             switch (finalFrameType)
             {
@@ -3830,12 +3816,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
 
             await WaitForStreamErrorAsync(1, Http2ErrorCode.INTERNAL_ERROR, "The connection was aborted by the application.");
 
-            // There's a race when the appfunc is exiting about how soon it unregisters the stream.
-            for (var i = 0; i < 10; i++)
-            {
-                await SendDataAsync(1, new byte[100], endStream: false);
-            }
-
             // These would be refused if the cool-down period had expired
             switch (finalFrameType)
             {
@@ -3860,7 +3840,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
         }
 
         [Theory]
-        [InlineData(Http2FrameType.DATA)]
+        [InlineData(Http2FrameType.DATA, Skip = "Fixed in master with https://github.com/aspnet/KestrelHttpServer/pull/3024/")]
         [InlineData(Http2FrameType.HEADERS)]
         [InlineData(Http2FrameType.CONTINUATION)]
         public async Task AbortedStream_ResetsAndDrainsRequest_RefusesFramesAfterEndOfStream(Http2FrameType finalFrameType)
@@ -3877,21 +3857,22 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
 
             await WaitForStreamErrorAsync(1, Http2ErrorCode.INTERNAL_ERROR, "The connection was aborted by the application.");
 
-            // There's a race when the appfunc is exiting about how soon it unregisters the stream.
-            for (var i = 0; i < 10; i++)
-            {
-                await SendDataAsync(1, new byte[100], endStream: false);
-            }
-
             switch (finalFrameType)
             {
                 case Http2FrameType.DATA:
                     await SendDataAsync(1, new byte[100], endStream: true);
                     // An extra one to break it
                     await SendDataAsync(1, new byte[100], endStream: true);
-
+                    
-                    await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(ignoreNonGoAwayFrames: false, expectedLastStreamId: 1, Http2ErrorCode.STREAM_CLOSED,
+                    // There's a race where either of these messages could be logged, depending on if the stream cleanup has finished yet.
-                        CoreStrings.FormatHttp2ErrorStreamClosed(Http2FrameType.DATA, 1));
+                    await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(
+                        ignoreNonGoAwayFrames: false,
+                        expectedLastStreamId: 1,
+                        expectedErrorCode: Http2ErrorCode.STREAM_CLOSED,
+                        expectedErrorMessage: new[] {
+                            CoreStrings.FormatHttp2ErrorStreamClosed(Http2FrameType.DATA, streamId: 1),
+                            CoreStrings.FormatHttp2ErrorStreamHalfClosedRemote(Http2FrameType.DATA, streamId: 1)
+                        });
                     break;
 
                 case Http2FrameType.HEADERS:
@@ -3899,8 +3880,15 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
                     // An extra one to break it
                     await SendHeadersAsync(1, Http2HeadersFrameFlags.END_STREAM | Http2HeadersFrameFlags.END_HEADERS, _requestTrailers);
 
-                    await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(ignoreNonGoAwayFrames: false, expectedLastStreamId: 1, Http2ErrorCode.STREAM_CLOSED,
+                    // There's a race where either of these messages could be logged, depending on if the stream cleanup has finished yet.
-                        CoreStrings.FormatHttp2ErrorStreamClosed(Http2FrameType.HEADERS, 1));
+                    await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(
+                        ignoreNonGoAwayFrames: false,
+                        expectedLastStreamId: 1,
+                        expectedErrorCode: Http2ErrorCode.STREAM_CLOSED,
+                        expectedErrorMessage: new[] {
+                            CoreStrings.FormatHttp2ErrorStreamClosed(Http2FrameType.HEADERS, streamId: 1),
+                            CoreStrings.FormatHttp2ErrorStreamHalfClosedRemote(Http2FrameType.HEADERS, streamId: 1)
+                        });
                     break;
 
                 case Http2FrameType.CONTINUATION:
@@ -3908,8 +3896,16 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
                     await SendContinuationAsync(1, Http2ContinuationFrameFlags.END_HEADERS, _requestTrailers);
                     // An extra one to break it. It's not a Continuation because that would fail with an error that no headers were in progress.
                     await SendHeadersAsync(1, Http2HeadersFrameFlags.END_STREAM, _requestTrailers);
-                    await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(ignoreNonGoAwayFrames: false, expectedLastStreamId: 1, Http2ErrorCode.STREAM_CLOSED,
+
-                        CoreStrings.FormatHttp2ErrorStreamClosed(Http2FrameType.HEADERS, 1));
+                    // There's a race where either of these messages could be logged, depending on if the stream cleanup has finished yet.
+                    await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(
+                        ignoreNonGoAwayFrames: false,
+                        expectedLastStreamId: 1,
+                        expectedErrorCode: Http2ErrorCode.STREAM_CLOSED,
+                        expectedErrorMessage: new[] {
+                            CoreStrings.FormatHttp2ErrorStreamClosed(Http2FrameType.HEADERS, streamId: 1),
+                            CoreStrings.FormatHttp2ErrorStreamHalfClosedRemote(Http2FrameType.HEADERS, streamId: 1)
+                        });
                     break;
                 default:
                     throw new NotImplementedException(finalFrameType.ToString());
@@ -3933,11 +3929,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
 
             await WaitForStreamErrorAsync(1, Http2ErrorCode.INTERNAL_ERROR, "The connection was aborted by the application.");
 
-            // There's a race when the appfunc is exiting about how soon it unregisters the stream.
-            for (var i = 0; i < 10; i++)
-            {
-                await SendDataAsync(1, new byte[100], endStream: false);
-            }
             await SendRstStreamAsync(1);
 
             // Send an extra frame to make it fail
@@ -3955,8 +3946,15 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
                     throw new NotImplementedException(finalFrameType.ToString());
             }
 
-            await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(ignoreNonGoAwayFrames: false, expectedLastStreamId: 1, Http2ErrorCode.STREAM_CLOSED,
+            // There's a race where either of these messages could be logged, depending on if the stream cleanup has finished yet.
-                CoreStrings.FormatHttp2ErrorStreamClosed(finalFrameType, 1));
+            await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(
+                ignoreNonGoAwayFrames: false,
+                expectedLastStreamId: 1,
+                expectedErrorCode: Http2ErrorCode.STREAM_CLOSED,
+                expectedErrorMessage: new[] {
+                    CoreStrings.FormatHttp2ErrorStreamClosed(finalFrameType, streamId: 1),
+                    CoreStrings.FormatHttp2ErrorStreamHalfClosedRemote(finalFrameType, streamId: 1)
+                });
         }
 
         public static TheoryData<byte[]> UpperCaseHeaderNameData

test/Kestrel.InMemory.FunctionalTests/Http2/Http2TestBase.cs

@@ -1110,7 +1110,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
             Assert.Equal(expectedErrorCode, frame.GoAwayErrorCode);
         }
 
-        protected async Task WaitForConnectionErrorAsync<TException>(bool ignoreNonGoAwayFrames, int expectedLastStreamId, Http2ErrorCode expectedErrorCode, string expectedErrorMessage)
+        protected async Task WaitForConnectionErrorAsync<TException>(bool ignoreNonGoAwayFrames, int expectedLastStreamId, Http2ErrorCode expectedErrorCode, params string[] expectedErrorMessage)
             where TException : Exception
         {
             var frame = await ReceiveFrameAsync();
@@ -1125,10 +1125,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
 
             VerifyGoAway(frame, expectedLastStreamId, expectedErrorCode);
 
-            if (expectedErrorMessage != null)
+            if (expectedErrorMessage?.Length > 0)
             {
                 var message = Assert.Single(TestApplicationErrorLogger.Messages, m => m.Exception is TException);
-                Assert.Contains(expectedErrorMessage, message.Exception.Message);
+
+                Assert.Contains(expectedErrorMessage, expected => message.Exception.Message.Contains(expected));
             }
 
             await _connectionTask;

test/Kestrel.InMemory.FunctionalTests/Http2/Http2TimeoutTests.cs

@@ -3,6 +3,7 @@
 
 using System;
 using System.Collections.Generic;
+using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Connections;
 using Microsoft.AspNetCore.Server.Kestrel.Core.Features;
@@ -191,7 +192,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
 
         [Theory]
         [InlineData(Http2FrameType.DATA)]
-        [InlineData(Http2FrameType.HEADERS)]
+        [InlineData(Http2FrameType.CONTINUATION, Skip = "https://github.com/aspnet/KestrelHttpServer/issues/3077")]
         public async Task AbortedStream_ResetsAndDrainsRequest_RefusesFramesAfterCooldownExpires(Http2FrameType finalFrameType)
         {
             var mockSystemClock = _serviceContext.MockSystemClock;
@@ -208,40 +209,55 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
 
             await WaitForStreamErrorAsync(1, Http2ErrorCode.INTERNAL_ERROR, "The connection was aborted by the application.");
 
-            // There's a race when the appfunc is exiting about how soon it unregisters the stream.
+            var cts = new CancellationTokenSource();
-            for (var i = 0; i < 10; i++)
+
+            async Task AdvanceClockAndSendFrames()
             {
-                await SendDataAsync(1, new byte[100], endStream: false);
+                if (finalFrameType == Http2FrameType.CONTINUATION)
+                {
+                    await SendHeadersAsync(1, Http2HeadersFrameFlags.END_STREAM, new byte[0]);
+                }
+
+                // There's a race when the appfunc is exiting about how soon it unregisters the stream, so retry until success.
+                while (!cts.Token.IsCancellationRequested)
+                {
+                    // Just past the timeout
+                    mockSystemClock.UtcNow += Constants.RequestBodyDrainTimeout + TimeSpan.FromTicks(1);
+                    (_connection as IRequestProcessor).Tick(mockSystemClock.UtcNow);
+
+                    // Send an extra frame to make it fail
+                    switch (finalFrameType)
+                    {
+                        case Http2FrameType.DATA:
+                            await SendDataAsync(1, new byte[100], endStream: false);
+                            break;
+
+                        case Http2FrameType.CONTINUATION:
+                            await SendContinuationAsync(1, Http2ContinuationFrameFlags.NONE, new byte[0]);
+                            break;
+
+                        default:
+                            throw new NotImplementedException(finalFrameType.ToString());
+                    }
+
+                    if (!cts.Token.IsCancellationRequested)
+                    {
+                        await Task.Delay(10);
+                    }
+                }
             }
 
-            // Just short of the timeout
+            var sendTask = AdvanceClockAndSendFrames();
-            mockSystemClock.UtcNow += Constants.RequestBodyDrainTimeout;
-            (_connection as IRequestProcessor).Tick(mockSystemClock.UtcNow);
 
-            // Still fine
+            await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(
-            await SendDataAsync(1, new byte[100], endStream: false);
+                ignoreNonGoAwayFrames: false,
-
+                expectedLastStreamId: 1,
-            // Just past the timeout
+                Http2ErrorCode.STREAM_CLOSED,
-            mockSystemClock.UtcNow += TimeSpan.FromTicks(1);
-            (_connection as IRequestProcessor).Tick(mockSystemClock.UtcNow);
-
-            // Send an extra frame to make it fail
-            switch (finalFrameType)
-            {
-                case Http2FrameType.DATA:
-                    await SendDataAsync(1, new byte[100], endStream: true);
-                    break;
-
-                case Http2FrameType.HEADERS:
-                    await SendHeadersAsync(1, Http2HeadersFrameFlags.END_STREAM | Http2HeadersFrameFlags.END_HEADERS, _requestTrailers);
-                    break;
-
-                default:
-                    throw new NotImplementedException(finalFrameType.ToString());
-            }
-
-            await WaitForConnectionErrorAsync<Http2ConnectionErrorException>(ignoreNonGoAwayFrames: false, expectedLastStreamId: 1, Http2ErrorCode.STREAM_CLOSED,
                 CoreStrings.FormatHttp2ErrorStreamClosed(finalFrameType, 1));
+
+            cts.Cancel();
+
+            await sendTask.DefaultTimeout();
         }
 
         [Fact]