huahaofeng
/
aspnetcore
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Fix flakiness in connection reset logging tests.

This commit is contained in:
Cesar Blum Silveira 2017-03-23 21:52:29 -07:00 committed by GitHub
parent f090b7a9c6
commit 3e6303b6c1
1 changed files with 59 additions and 24 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

83
test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/RequestTests.cs
View File

@ -30,6 +30,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
public class RequestTests
{
private const int _connectionStartedEventId = 1;
private const int _connectionKeepAliveEventId = 9;
private const int _connectionResetEventId = 19;
private const int _semaphoreWaitTimeout = 2500;
@ -241,7 +242,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
[Fact]
public async Task ConnectionResetPriorToRequestIsLoggedAsDebug()
{
var connectionStartedTcs = new TaskCompletionSource<object>();
var connectionStarted = new SemaphoreSlim(0);
var connectionReset = new SemaphoreSlim(0);
var mockLogger = new Mock<ILogger>();
mockLogger
@ -251,7 +253,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
.Setup(logger => logger.Log(LogLevel.Debug, _connectionStartedEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()))
.Callback(() =>
{
connectionStartedTcs.SetResult(null);
connectionStarted.Release();
});
mockLogger
.Setup(logger => logger.Log(LogLevel.Debug, _connectionResetEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()))
.Callback(() =>
{
connectionReset.Release();
});
var mockLoggerFactory = new Mock<ILoggerFactory>();
@ -266,10 +274,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
.UseLoggerFactory(mockLoggerFactory.Object)
.UseKestrel()
.UseUrls($"http://127.0.0.1:0")
.Configure(app => app.Run(context =>
{
return TaskCache.CompletedTask;
}));
.Configure(app => app.Run(context => TaskCache.CompletedTask));
using (var host = builder.Build())
{
@ -280,23 +285,42 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
socket.Connect(new IPEndPoint(IPAddress.Loopback, host.GetPort()));
// Wait until connection is established
await connectionStartedTcs.Task.TimeoutAfter(TimeSpan.FromSeconds(10));
await connectionStarted.WaitAsync(TimeSpan.FromSeconds(10));
// Force a reset
socket.LingerState = new LingerOption(true, 0);
}
}
mockLogger.Verify(logger => logger.Log(LogLevel.Debug, _connectionResetEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()));
// If the reset is correctly logged as Debug, the wait below should complete shortly.
// This check MUST come before disposing the server, otherwise there's a race where the RST
// is still in flight when the connection is aborted, leading to the reset never being received
// and therefore not logged.
await connectionReset.WaitAsync(TimeSpan.FromSeconds(10));
}
}
[Fact]
public async Task ConnectionResetBetweenRequestsIsLoggedAsDebug()
{
var requestDone = new SemaphoreSlim(0);
var connectionReset = new SemaphoreSlim(0);
var mockLogger = new Mock<ILogger>();
mockLogger
.Setup(logger => logger.IsEnabled(It.IsAny<LogLevel>()))
.Returns(true);
mockLogger
.Setup(logger => logger.Log(LogLevel.Debug, _connectionKeepAliveEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()))
.Callback(() =>
{
requestDone.Release();
});
mockLogger
.Setup(logger => logger.Log(LogLevel.Debug, _connectionResetEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()))
.Callback(() =>
{
connectionReset.Release();
});
var mockLoggerFactory = new Mock<ILoggerFactory>();
mockLoggerFactory
@ -306,17 +330,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
.Setup(factory => factory.CreateLogger(It.IsNotIn(new[] { "Microsoft.AspNetCore.Server.Kestrel" })))
.Returns(Mock.Of<ILogger>());
var connectionStartedTcs = new TaskCompletionSource<object>();
var builder = new WebHostBuilder()
.UseLoggerFactory(mockLoggerFactory.Object)
.UseKestrel()
.UseUrls($"http://127.0.0.1:0")
.Configure(app => app.Run(context =>
{
connectionStartedTcs.SetResult(null);
return TaskCache.CompletedTask;
}));
.Configure(app => app.Run(context => TaskCache.CompletedTask));
using (var host = builder.Build())
{
@ -327,24 +346,36 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
socket.Connect(new IPEndPoint(IPAddress.Loopback, host.GetPort()));
socket.Send(Encoding.ASCII.GetBytes("GET / HTTP/1.1\r\n\r\n"));
// Wait until connection is established
await connectionStartedTcs.Task.TimeoutAfter(TimeSpan.FromSeconds(10));
// Wait until request is done being processed
await requestDone.WaitAsync(TimeSpan.FromSeconds(10));
// Force a reset
socket.LingerState = new LingerOption(true, 0);
}
}
mockLogger.Verify(logger => logger.Log(LogLevel.Debug, _connectionResetEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()));
// If the reset is correctly logged as Debug, the wait below should complete shortly.
// This check MUST come before disposing the server, otherwise there's a race where the RST
// is still in flight when the connection is aborted, leading to the reset never being received
// and therefore not logged.
await connectionReset.WaitAsync(TimeSpan.FromSeconds(10));
}
}
[Fact]
public async Task ConnectionResetMidRequestIsLoggedAsDebug()
{
var connectionReset = new SemaphoreSlim(0);
var mockLogger = new Mock<ILogger>();
mockLogger
.Setup(logger => logger.IsEnabled(It.IsAny<LogLevel>()))
.Returns(true);
mockLogger
.Setup(logger => logger.Log(LogLevel.Debug, _connectionResetEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()))
.Callback(() =>
{
connectionReset.Release();
});
var mockLoggerFactory = new Mock<ILoggerFactory>();
mockLoggerFactory
@ -354,7 +385,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
.Setup(factory => factory.CreateLogger(It.IsNotIn(new[] { "Microsoft.AspNetCore.Server.Kestrel" })))
.Returns(Mock.Of<ILogger>());
var connectionStartedTcs = new TaskCompletionSource<object>();
var requestStarted = new SemaphoreSlim(0);
var builder = new WebHostBuilder()
.UseLoggerFactory(mockLoggerFactory.Object)
@ -362,7 +393,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
.UseUrls($"http://127.0.0.1:0")
.Configure(app => app.Run(async context =>
{
connectionStartedTcs.SetResult(null);
requestStarted.Release();
await context.Request.Body.ReadAsync(new byte[1], 0, 1);
}));
@ -376,14 +407,18 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
socket.Send(Encoding.ASCII.GetBytes("GET / HTTP/1.1\r\n\r\n"));
// Wait until connection is established
await connectionStartedTcs.Task.TimeoutAfter(TimeSpan.FromSeconds(10));
await requestStarted.WaitAsync(TimeSpan.FromSeconds(10));
// Force a reset
socket.LingerState = new LingerOption(true, 0);
}
}
mockLogger.Verify(logger => logger.Log(LogLevel.Debug, _connectionResetEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()));
// If the reset is correctly logged as Debug, the wait below should complete shortly.
// This check MUST come before disposing the server, otherwise there's a race where the RST
// is still in flight when the connection is aborted, leading to the reset never being received
// and therefore not logged.
await connectionReset.WaitAsync(TimeSpan.FromSeconds(10));
}
}
[Fact]