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

Fix flaky test and improve TestServer (#1859)

This commit is contained in:
Stephen Halter 2017-05-24 15:45:54 -07:00 committed by GitHub
parent 197eb43d8a
commit 6c0af445e5
8 changed files with 152 additions and 163 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

47
test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/FrameConnectionManagerTests.cs
View File

@ -5,11 +5,9 @@ using System;
using System.Diagnostics;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Hosting;
using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure;
using Microsoft.AspNetCore.Testing;
using Microsoft.AspNetCore.Testing.xunit;
using Microsoft.Extensions.Logging;
using Moq;
using Xunit;
@ -17,7 +15,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
{
public class FrameConnectionManagerTests
{
private const int _applicationNeverCompletedId = 23;
[ConditionalFact]
[NoDebuggerCondition]
@ -31,45 +28,23 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
var logWh = new SemaphoreSlim(0);
var appStartedWh = new SemaphoreSlim(0);
var mockLogger = new Mock<ILogger>();
mockLogger
.Setup(logger => logger.IsEnabled(It.IsAny<LogLevel>()))
.Returns(true);
mockLogger
.Setup(logger => logger.Log(LogLevel.Critical, _applicationNeverCompletedId, It.IsAny<object>(), null,
It.IsAny<Func<object, Exception, string>>()))
var mockTrace = new Mock<IKestrelTrace>();
mockTrace
.Setup(trace => trace.ApplicationNeverCompleted(It.IsAny<string>()))
.Callback(() =>
{
logWh.Release();
});
var mockLoggerFactory = new Mock<ILoggerFactory>();
mockLoggerFactory
.Setup(factory => factory.CreateLogger("Microsoft.AspNetCore.Server.Kestrel"))
.Returns(mockLogger.Object);
mockLoggerFactory
.Setup(factory => factory.CreateLogger(It.IsNotIn("Microsoft.AspNetCore.Server.Kestrel")))
.Returns(Mock.Of<ILogger>());
var builder = new WebHostBuilder()
.UseLoggerFactory(mockLoggerFactory.Object)
.UseKestrel()
.UseUrls("http://127.0.0.1:0")
.Configure(app =>
using (var server = new TestServer(context =>
{
app.Run(context =>
{
appStartedWh.Release();
var tcs = new TaskCompletionSource<object>();
return tcs.Task;
});
});
using (var host = builder.Build())
appStartedWh.Release();
var tcs = new TaskCompletionSource<object>();
return tcs.Task;
},
new TestServiceContext(new KestrelTestLoggerFactory(), mockTrace.Object)))
{
host.Start();
using (var connection = new TestConnection(host.GetPort()))
using (var connection = server.CreateConnection())
{
await connection.Send("GET / HTTP/1.1",
"Host:",

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

@ -19,7 +19,6 @@ using Microsoft.AspNetCore.Http.Features;
using Microsoft.AspNetCore.Server.Kestrel.Core;
using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http;
using Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions;
using Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Networking;
using Microsoft.AspNetCore.Testing;
using Microsoft.AspNetCore.Testing.xunit;
using Microsoft.Extensions.Internal;
@ -34,7 +33,6 @@ 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;
@ -257,54 +255,48 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
{
var connectionStarted = new SemaphoreSlim(0);
var connectionReset = new SemaphoreSlim(0);
var loggedHigherThanDebug = false;
var mockLogger = new Mock<ILogger>();
mockLogger
.Setup(logger => logger.IsEnabled(It.IsAny<LogLevel>()))
.Returns(true);
mockLogger
.Setup(logger => logger.Log(LogLevel.Debug, _connectionStartedEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()))
.Callback(() =>
.Setup(logger => logger.Log(It.IsAny<LogLevel>(), It.IsAny<EventId>(), It.IsAny<object>(), It.IsAny<Exception>(), It.IsAny<Func<object, Exception, string>>()))
.Callback<LogLevel, EventId, object, Exception, Func<object, Exception, string>>((logLevel, eventId, state, exception, formatter) =>
{
connectionStarted.Release();
});
mockLogger
.Setup(logger => logger.Log(LogLevel.Debug, _connectionResetEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()))
.Callback(() =>
{
connectionReset.Release();
if (eventId.Id == _connectionStartedEventId)
{
connectionStarted.Release();
}
else if (eventId.Id == _connectionResetEventId)
{
connectionReset.Release();
}
if (logLevel > LogLevel.Debug)
{
loggedHigherThanDebug = true;
}
});
var mockLoggerFactory = new Mock<ILoggerFactory>();
mockLoggerFactory
.Setup(factory => factory.CreateLogger("Microsoft.AspNetCore.Server.Kestrel"))
.Returns(mockLogger.Object);
mockLoggerFactory
.Setup(factory => factory.CreateLogger("Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv"))
.Returns(mockLogger.Object);
mockLoggerFactory
.Setup(factory => factory.CreateLogger(It.IsNotIn("Microsoft.AspNetCore.Server.Kestrel", "Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv")))
.Setup(factory => factory.CreateLogger(It.IsAny<string>()))
.Returns(Mock.Of<ILogger>());
mockLoggerFactory
.Setup(factory => factory.CreateLogger(It.IsIn("Microsoft.AspNetCore.Server.Kestrel", "Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv")))
.Returns(mockLogger.Object);
var builder = new WebHostBuilder()
.UseLoggerFactory(mockLoggerFactory.Object)
.UseKestrel()
.UseUrls("http://127.0.0.1:0")
.Configure(app => app.Run(context => TaskCache.CompletedTask));
using (var host = builder.Build())
using (var server = new TestServer(context => TaskCache.CompletedTask, new TestServiceContext(mockLoggerFactory.Object)))
{
host.Start();
using (var socket = new Socket(AddressFamily.InterNetwork, SocketType.Stream, ProtocolType.Tcp))
using (var connection = server.CreateConnection())
{
socket.Connect(new IPEndPoint(IPAddress.Loopback, host.GetPort()));
// Wait until connection is established
Assert.True(await connectionStarted.WaitAsync(TimeSpan.FromSeconds(10)));
// Force a reset
socket.LingerState = new LingerOption(true, 0);
connection.Socket.LingerState = new LingerOption(true, 0);
}
// If the reset is correctly logged as Debug, the wait below should complete shortly.
@ -313,63 +305,64 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
// and therefore not logged.
Assert.True(await connectionReset.WaitAsync(TimeSpan.FromSeconds(10)));
}
Assert.False(loggedHigherThanDebug);
}
[Fact(Skip= "https://github.com/aspnet/KestrelHttpServer/issues/1835")]
[Fact]
public async Task ConnectionResetBetweenRequestsIsLoggedAsDebug()
{
var requestDone = new SemaphoreSlim(0);
var connectionReset = new SemaphoreSlim(0);
var loggedHigherThanDebug = false;
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(() =>
.Setup(logger => logger.Log(It.IsAny<LogLevel>(), It.IsAny<EventId>(), It.IsAny<object>(), It.IsAny<Exception>(), It.IsAny<Func<object, Exception, string>>()))
.Callback<LogLevel, EventId, object, Exception, Func<object, Exception, string>>((logLevel, eventId, state, exception, formatter) =>
{
requestDone.Release();
});
mockLogger
.Setup(logger => logger.Log(LogLevel.Debug, _connectionResetEventId, It.IsAny<object>(), null, It.IsAny<Func<object, Exception, string>>()))
.Callback(() =>
{
connectionReset.Release();
if (eventId.Id == _connectionResetEventId)
{
connectionReset.Release();
}
if (logLevel > LogLevel.Debug)
{
loggedHigherThanDebug = true;
}
});
var mockLoggerFactory = new Mock<ILoggerFactory>();
mockLoggerFactory
.Setup(factory => factory.CreateLogger("Microsoft.AspNetCore.Server.Kestrel"))
.Returns(mockLogger.Object);
mockLoggerFactory
.Setup(factory => factory.CreateLogger("Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv"))
.Returns(mockLogger.Object);
mockLoggerFactory
.Setup(factory => factory.CreateLogger(It.IsNotIn("Microsoft.AspNetCore.Server.Kestrel", "Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv")))
.Setup(factory => factory.CreateLogger(It.IsAny<string>()))
.Returns(Mock.Of<ILogger>());
mockLoggerFactory
.Setup(factory => factory.CreateLogger(It.IsIn("Microsoft.AspNetCore.Server.Kestrel", "Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv")))
.Returns(mockLogger.Object);
var builder = new WebHostBuilder()
.UseLoggerFactory(mockLoggerFactory.Object)
.UseKestrel()
.UseUrls("http://127.0.0.1:0")
.Configure(app => app.Run(context => TaskCache.CompletedTask));
using (var host = builder.Build())
using (var server = new TestServer(context => TaskCache.CompletedTask, new TestServiceContext(mockLoggerFactory.Object)))
{
host.Start();
using (var socket = new Socket(AddressFamily.InterNetwork, SocketType.Stream, ProtocolType.Tcp))
using (var connection = server.CreateConnection())
{
socket.Connect(new IPEndPoint(IPAddress.Loopback, host.GetPort()));
socket.Send(Encoding.ASCII.GetBytes("GET / HTTP/1.1\r\nHost:\r\n\r\n"));
await connection.Send(
"GET / HTTP/1.1",
"Host:",
"",
"");
// Wait until request is done being processed
Assert.True(await requestDone.WaitAsync(TimeSpan.FromSeconds(10)));
// Make sure the response is fully received, so a write failure (e.g. EPIPE) doesn't cause
// a more critical log message.
await connection.Receive(
"HTTP/1.1 200 OK",
$"Date: {server.Context.DateHeaderValue}",
"Content-Length: 0",
"",
"");
// Force a reset
socket.LingerState = new LingerOption(true, 0);
connection.Socket.LingerState = new LingerOption(true, 0);
}
// If the reset is correctly logged as Debug, the wait below should complete shortly.
@ -378,61 +371,64 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
// and therefore not logged.
Assert.True(await connectionReset.WaitAsync(TimeSpan.FromSeconds(10)));
}
Assert.False(loggedHigherThanDebug);
}
[Fact]
public async Task ConnectionResetMidRequestIsLoggedAsDebug()
{
var requestStarted = new SemaphoreSlim(0);
var connectionReset = new SemaphoreSlim(0);
var loggedHigherThanDebug = false;
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();
});
.Setup(logger => logger.Log(It.IsAny<LogLevel>(), It.IsAny<EventId>(), It.IsAny<object>(), It.IsAny<Exception>(), It.IsAny<Func<object, Exception, string>>()))
.Callback<LogLevel, EventId, object, Exception, Func<object, Exception, string>>((logLevel, eventId, state, exception, formatter) =>
{
if (eventId.Id == _connectionResetEventId)
{
connectionReset.Release();
}
if (logLevel > LogLevel.Debug)
{
loggedHigherThanDebug = true;
}
});
var mockLoggerFactory = new Mock<ILoggerFactory>();
mockLoggerFactory
.Setup(factory => factory.CreateLogger("Microsoft.AspNetCore.Server.Kestrel"))
.Returns(mockLogger.Object);
mockLoggerFactory
.Setup(factory => factory.CreateLogger("Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv"))
.Returns(mockLogger.Object);
mockLoggerFactory
.Setup(factory => factory.CreateLogger(It.IsNotIn("Microsoft.AspNetCore.Server.Kestrel", "Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv")))
.Setup(factory => factory.CreateLogger(It.IsAny<string>()))
.Returns(Mock.Of<ILogger>());
mockLoggerFactory
.Setup(factory => factory.CreateLogger(It.IsIn("Microsoft.AspNetCore.Server.Kestrel", "Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv")))
.Returns(mockLogger.Object);
var requestStarted = new SemaphoreSlim(0);
var builder = new WebHostBuilder()
.UseLoggerFactory(mockLoggerFactory.Object)
.UseKestrel()
.UseUrls("http://127.0.0.1:0")
.Configure(app => app.Run(async context =>
using (var server = new TestServer(async context =>
{
requestStarted.Release();
await context.Request.Body.ReadAsync(new byte[1], 0, 1);
}));
using (var host = builder.Build())
},
new TestServiceContext(mockLoggerFactory.Object)))
{
host.Start();
using (var socket = new Socket(AddressFamily.InterNetwork, SocketType.Stream, ProtocolType.Tcp))
using (var connection = server.CreateConnection())
{
socket.Connect(new IPEndPoint(IPAddress.Loopback, host.GetPort()));
socket.Send(Encoding.ASCII.GetBytes("GET / HTTP/1.1\r\nHost:\r\n\r\n"));
await connection.Send(
"GET / HTTP/1.1",
"Host:",
"",
"");
// Wait until connection is established
Assert.True(await requestStarted.WaitAsync(TimeSpan.FromSeconds(10)));
// Force a reset
socket.LingerState = new LingerOption(true, 0);
connection.Socket.LingerState = new LingerOption(true, 0);
}
// If the reset is correctly logged as Debug, the wait below should complete shortly.
@ -441,6 +437,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
// and therefore not logged.
Assert.True(await connectionReset.WaitAsync(TimeSpan.FromSeconds(10)));
}
Assert.False(loggedHigherThanDebug);
}
[Fact]

4
test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/ResponseTests.cs
View File

@ -20,6 +20,7 @@ using Microsoft.AspNetCore.Server.Kestrel.Core.Internal;
using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http;
using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure;
using Microsoft.AspNetCore.Testing;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Internal;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Primitives;
@ -300,7 +301,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
disposedTcs.TrySetResult(c.Response.StatusCode);
});
using (var server = new TestServer(handler, new TestServiceContext(), mockHttpContextFactory.Object))
using (var server = new TestServer(handler, new TestServiceContext(), new ListenOptions(new IPEndPoint(IPAddress.Loopback, 0)),
services => services.AddSingleton(mockHttpContextFactory.Object)))
{
if (!sendMalformedRequest)
{

20
test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/TestServer.cs
View File

@ -34,21 +34,16 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
}
public TestServer(RequestDelegate app, TestServiceContext context)
: this(app, context, httpContextFactory: null)
{
}
public TestServer(RequestDelegate app, TestServiceContext context, IHttpContextFactory httpContextFactory)
: this(app, context, new ListenOptions(new IPEndPoint(IPAddress.Loopback, 0)), httpContextFactory)
: this(app, context, new ListenOptions(new IPEndPoint(IPAddress.Loopback, 0)))
{
}
public TestServer(RequestDelegate app, TestServiceContext context, ListenOptions listenOptions)
: this(app, context, listenOptions, null)
: this(app, context, listenOptions, _ => { })
{
}
public TestServer(RequestDelegate app, TestServiceContext context, ListenOptions listenOptions, IHttpContextFactory httpContextFactory)
public TestServer(RequestDelegate app, TestServiceContext context, ListenOptions listenOptions, Action<IServiceCollection> configureServices)
{
_app = app;
_listenOptions = listenOptions;
@ -61,13 +56,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
})
.ConfigureServices(services =>
{
if (httpContextFactory != null)
{
services.AddSingleton(httpContextFactory);
}
services.AddSingleton<IStartup>(this);
services.AddSingleton<ILoggerFactory>(new KestrelTestLoggerFactory(context.ErrorLogger));
services.AddSingleton(context.LoggerFactory);
services.AddSingleton<IServer>(sp =>
{
// Manually configure options on the TestServiceContext.
@ -79,6 +69,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
}
return new KestrelServer(sp.GetRequiredService<ITransportFactory>(), context);
});
configureServices(services);
})
.UseSetting(WebHostDefaults.ApplicationKey, typeof(TestServer).GetTypeInfo().Assembly.FullName)
.Build();

5
test/shared/KestrelTestLoggerFactory.cs
View File

@ -10,6 +10,11 @@ namespace Microsoft.AspNetCore.Testing
{
private readonly ILogger _testLogger;
public KestrelTestLoggerFactory()
: this(new TestApplicationErrorLogger())
{
}
public KestrelTestLoggerFactory(ILogger testLogger)
{
_testLogger = testLogger;

6
test/shared/TestApplicationErrorLogger.cs
View File

@ -15,8 +15,6 @@ namespace Microsoft.AspNetCore.Testing
// Application errors are logged using 13 as the eventId.
private const int ApplicationErrorEventId = 13;
private TaskCompletionSource<object> _messageLoggedTcs = new TaskCompletionSource<object>();
public bool ThrowOnCriticalErrors { get; set; } = true;
public ConcurrentBag<LogMessage> Messages { get; } = new ConcurrentBag<LogMessage>();
@ -27,8 +25,6 @@ namespace Microsoft.AspNetCore.Testing
public int ApplicationErrorsLogged => Messages.Count(message => message.EventId.Id == ApplicationErrorEventId);
public Task MessageLoggedTask => _messageLoggedTcs.Task;
public IDisposable BeginScope<TState>(TState state)
{
return new Disposable(() => { });
@ -60,8 +56,6 @@ namespace Microsoft.AspNetCore.Testing
Exception = exception,
Message = formatter(state, exception)
});
_messageLoggedTcs.TrySetResult(null);
}
public class LogMessage

33
test/shared/TestConnection.cs
View File

@ -17,35 +17,48 @@ namespace Microsoft.AspNetCore.Testing
/// </summary>
public class TestConnection : IDisposable
{
private Socket _socket;
private NetworkStream _stream;
private StreamReader _reader;
private static readonly TimeSpan Timeout = TimeSpan.FromMinutes(1);
private readonly bool _ownsSocket;
private readonly Socket _socket;
private readonly NetworkStream _stream;
private readonly StreamReader _reader;
public TestConnection(int port)
: this(port, AddressFamily.InterNetwork)
{
}
public TestConnection(int port, AddressFamily addressFamily)
: this(CreateConnectedLoopbackSocket(port, addressFamily), ownsSocket: true)
{
Create(port, addressFamily);
}
public StreamReader Reader => _reader;
public void Create(int port, AddressFamily addressFamily)
public TestConnection(Socket socket)
: this(socket, ownsSocket: false)
{
_socket = CreateConnectedLoopbackSocket(port, addressFamily);
}
_stream = new NetworkStream(_socket, false);
private TestConnection(Socket socket, bool ownsSocket)
{
_ownsSocket = ownsSocket;
_socket = socket;
_stream = new NetworkStream(_socket, ownsSocket: false);
_reader = new StreamReader(_stream, Encoding.ASCII);
}
public Socket Socket => _socket;
public StreamReader Reader => _reader;
public void Dispose()
{
_stream.Dispose();
_socket.Dispose();
if (_ownsSocket)
{
_socket.Dispose();
}
}
public async Task SendAll(params string[] lines)

16
test/shared/TestServiceContext.cs
View File

@ -12,9 +12,19 @@ namespace Microsoft.AspNetCore.Testing
public class TestServiceContext : ServiceContext
{
public TestServiceContext()
: this(new KestrelTestLoggerFactory())
{
ErrorLogger = new TestApplicationErrorLogger();
Log = new TestKestrelTrace(ErrorLogger);
}
public TestServiceContext(ILoggerFactory loggerFactory)
: this(loggerFactory, new KestrelTrace(loggerFactory.CreateLogger("Microsoft.AspNetCore.Server.Kestrel")))
{
}
public TestServiceContext(ILoggerFactory loggerFactory, IKestrelTrace kestrelTrace)
{
LoggerFactory = loggerFactory;
Log = kestrelTrace;
ThreadPool = new LoggingThreadPool(Log);
SystemClock = new MockSystemClock();
DateHeaderValueManager = new DateHeaderValueManager(SystemClock);
@ -27,7 +37,7 @@ namespace Microsoft.AspNetCore.Testing
};
}
public TestApplicationErrorLogger ErrorLogger { get; }
public ILoggerFactory LoggerFactory { get; }
public string DateHeaderValue { get; }
}