more logging (#417)

This commit is contained in:
Andrew Stanton-Nurse 2017-04-24 12:38:39 -07:00 committed by GitHub
parent fc54ffc96e
commit 1018a20c61
4 changed files with 125 additions and 71 deletions

View File

@ -1,4 +1,4 @@
// Copyright (c) .NET Foundation. All rights reserved. // Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using System; using System;

View File

@ -19,6 +19,7 @@
<ProjectReference Include="..\..\src\Microsoft.AspNetCore.SignalR.Client\Microsoft.AspNetCore.SignalR.Client.csproj" /> <ProjectReference Include="..\..\src\Microsoft.AspNetCore.SignalR.Client\Microsoft.AspNetCore.SignalR.Client.csproj" />
<ProjectReference Include="..\..\src\Microsoft.AspNetCore.Sockets.Client\Microsoft.AspNetCore.Sockets.Client.csproj" /> <ProjectReference Include="..\..\src\Microsoft.AspNetCore.Sockets.Client\Microsoft.AspNetCore.Sockets.Client.csproj" />
<PackageReference Include="Microsoft.Extensions.Logging" Version="$(AspNetCoreVersion)" /> <PackageReference Include="Microsoft.Extensions.Logging" Version="$(AspNetCoreVersion)" />
<PackageReference Include="Microsoft.Extensions.Logging.Testing" Version="$(AspNetCoreVersion)" />
<PackageReference Include="Microsoft.NET.Test.Sdk" Version="$(TestSdkVersion)" /> <PackageReference Include="Microsoft.NET.Test.Sdk" Version="$(TestSdkVersion)" />
<PackageReference Include="Moq" Version="$(MoqVersion)" /> <PackageReference Include="Moq" Version="$(MoqVersion)" />
<PackageReference Include="xunit.runner.visualstudio" Version="$(XunitVersion)" /> <PackageReference Include="xunit.runner.visualstudio" Version="$(XunitVersion)" />

View File

@ -1,4 +1,4 @@
// Copyright (c) .NET Foundation. All rights reserved. // Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using System; using System;
@ -16,6 +16,7 @@ using Xunit;
using ClientConnection = Microsoft.AspNetCore.Sockets.Client.Connection; using ClientConnection = Microsoft.AspNetCore.Sockets.Client.Connection;
using Microsoft.AspNetCore.SignalR.Tests.Common; using Microsoft.AspNetCore.SignalR.Tests.Common;
using Xunit.Abstractions; using Xunit.Abstractions;
using Microsoft.Extensions.Logging.Testing;
namespace Microsoft.AspNetCore.SignalR.Tests namespace Microsoft.AspNetCore.SignalR.Tests
{ {
@ -26,13 +27,11 @@ namespace Microsoft.AspNetCore.SignalR.Tests
} }
[Collection(EndToEndTestsCollection.Name)] [Collection(EndToEndTestsCollection.Name)]
public class EndToEndTests public class EndToEndTests : LoggedTest
{ {
private readonly ITestOutputHelper _output;
private readonly ServerFixture _serverFixture; private readonly ServerFixture _serverFixture;
public EndToEndTests(ServerFixture serverFixture, ITestOutputHelper output) public EndToEndTests(ServerFixture serverFixture, ITestOutputHelper output) : base(output)
{ {
if (serverFixture == null) if (serverFixture == null)
{ {
@ -40,25 +39,39 @@ namespace Microsoft.AspNetCore.SignalR.Tests
} }
_serverFixture = serverFixture; _serverFixture = serverFixture;
_output = output;
} }
[ConditionalFact] [ConditionalFact]
[OSSkipCondition(OperatingSystems.Windows, WindowsVersions.Win7, WindowsVersions.Win2008R2, SkipReason = "No WebSockets Client for this platform")] [OSSkipCondition(OperatingSystems.Windows, WindowsVersions.Win7, WindowsVersions.Win2008R2, SkipReason = "No WebSockets Client for this platform")]
public async Task WebSocketsTest() public async Task WebSocketsTest()
{ {
const string message = "Hello, World!"; using (StartLog(out var loggerFactory))
using (var ws = new ClientWebSocket())
{ {
await ws.ConnectAsync(new Uri(_serverFixture.WebSocketsUrl + "/echo/ws"), CancellationToken.None); var logger = loggerFactory.CreateLogger<EndToEndTests>();
var bytes = Encoding.UTF8.GetBytes(message);
await ws.SendAsync(new ArraySegment<byte>(bytes), WebSocketMessageType.Binary, true, CancellationToken.None);
var buffer = new ArraySegment<byte>(new byte[1024]);
var result = await ws.ReceiveAsync(buffer, CancellationToken.None);
Assert.Equal(bytes, buffer.Array.AsSpan().Slice(0, message.Length).ToArray()); const string message = "Hello, World!";
using (var ws = new ClientWebSocket())
{
string socketUrl = _serverFixture.WebSocketsUrl + "/echo/ws";
await ws.CloseAsync(WebSocketCloseStatus.Empty, "", CancellationToken.None); logger.LogInformation("Connecting WebSocket to {socketUrl}", socketUrl);
await ws.ConnectAsync(new Uri(socketUrl), CancellationToken.None).OrTimeout();
var bytes = Encoding.UTF8.GetBytes(message);
logger.LogInformation("Sending {length} byte frame", bytes.Length);
await ws.SendAsync(new ArraySegment<byte>(bytes), WebSocketMessageType.Binary, true, CancellationToken.None).OrTimeout();
logger.LogInformation("Receiving frame");
var buffer = new ArraySegment<byte>(new byte[1024]);
var result = await ws.ReceiveAsync(buffer, CancellationToken.None).OrTimeout();
logger.LogInformation("Received {length} byte frame", result.Count);
Assert.Equal(bytes, buffer.Array.AsSpan().Slice(0, result.Count).ToArray());
logger.LogInformation("Closing socket");
await ws.CloseAsync(WebSocketCloseStatus.Empty, "", CancellationToken.None).OrTimeout();
logger.LogInformation("Closed socket");
}
} }
} }
@ -67,39 +80,57 @@ namespace Microsoft.AspNetCore.SignalR.Tests
[MemberData(nameof(TransportTypes))] [MemberData(nameof(TransportTypes))]
public async Task ConnectionCanSendAndReceiveMessages(TransportType transportType) public async Task ConnectionCanSendAndReceiveMessages(TransportType transportType)
{ {
const string message = "Major Key"; using (StartLog(out var loggerFactory, testName: $"ConnectionCanSendAndReceiveMessages_{transportType.ToString()}"))
var baseUrl = _serverFixture.BaseUrl;
var loggerFactory = new LoggerFactory();
loggerFactory.AddXunit(_output, LogLevel.Trace);
var connection = new ClientConnection(new Uri(baseUrl + "/echo"), loggerFactory);
try
{ {
var receiveTcs = new TaskCompletionSource<string>(); var logger = loggerFactory.CreateLogger<EndToEndTests>();
connection.Received += (data, format) => receiveTcs.TrySetResult(Encoding.UTF8.GetString(data));
connection.Closed += e => const string message = "Major Key";
var baseUrl = _serverFixture.BaseUrl;
string url = baseUrl + "/echo";
var connection = new ClientConnection(new Uri(url), loggerFactory);
try
{ {
if (e != null) var receiveTcs = new TaskCompletionSource<string>();
connection.Received += (data, format) =>
{ {
receiveTcs.TrySetException(e); logger.LogInformation("Received {length} byte message", data.Length);
} receiveTcs.TrySetResult(Encoding.UTF8.GetString(data));
else };
connection.Closed += e =>
{ {
receiveTcs.TrySetResult(null); logger.LogInformation("Connection closed");
} if (e != null)
}; {
receiveTcs.TrySetException(e);
}
else
{
receiveTcs.TrySetResult(null);
}
};
await connection.StartAsync(transportType); logger.LogInformation("Starting connection to {url}", url);
await connection.StartAsync(transportType).OrTimeout();
logger.LogInformation("Started connection to {url}", url);
await connection.SendAsync(Encoding.UTF8.GetBytes(message), MessageType.Text); var bytes = Encoding.UTF8.GetBytes(message);
logger.LogInformation("Sending {length} byte message", bytes.Length);
await connection.SendAsync(bytes, MessageType.Text).OrTimeout();
logger.LogInformation("Sent message", bytes.Length);
var receiveData = new ReceiveData(); var receiveData = new ReceiveData();
Assert.Equal(message, await receiveTcs.Task.OrTimeout()); logger.LogInformation("Receiving message");
} Assert.Equal(message, await receiveTcs.Task.OrTimeout());
finally logger.LogInformation("Completed receive");
{ }
await connection.DisposeAsync(); finally
{
logger.LogInformation("Disposing Connection");
await connection.DisposeAsync().OrTimeout();
logger.LogInformation("Disposed Connection");
}
} }
} }
@ -117,28 +148,45 @@ namespace Microsoft.AspNetCore.SignalR.Tests
[MemberData(nameof(MessageSizesData))] [MemberData(nameof(MessageSizesData))]
public async Task ConnectionCanSendAndReceiveDifferentMessageSizesWebSocketsTransport(string message) public async Task ConnectionCanSendAndReceiveDifferentMessageSizesWebSocketsTransport(string message)
{ {
var baseUrl = _serverFixture.BaseUrl; using (StartLog(out var loggerFactory, testName: $"ConnectionCanSendAndReceiveDifferentMessageSizesWebSocketsTransport_{message.Length}"))
var loggerFactory = new LoggerFactory();
loggerFactory.AddXunit(_output, LogLevel.Debug);
var connection = new ClientConnection(new Uri(baseUrl + "/echo"), loggerFactory);
try
{ {
var receiveTcs = new TaskCompletionSource<byte[]>(); var logger = loggerFactory.CreateLogger<EndToEndTests>();
connection.Received += (data, messageType) => receiveTcs.SetResult(data);
await connection.StartAsync(TransportType.WebSockets); var baseUrl = _serverFixture.BaseUrl;
await connection.SendAsync(Encoding.UTF8.GetBytes(message), MessageType.Text); string url = baseUrl + "/echo";
var connection = new ClientConnection(new Uri(url), loggerFactory);
try
{
var receiveTcs = new TaskCompletionSource<byte[]>();
connection.Received += (data, messageType) =>
{
logger.LogInformation("Received {length} byte message", data.Length);
receiveTcs.TrySetResult(data);
};
var receiveData = new ReceiveData(); logger.LogInformation("Starting connection to {url}", url);
await connection.StartAsync(TransportType.WebSockets).OrTimeout();
logger.LogInformation("Started connection to {url}", url);
var receivedData = await receiveTcs.Task.OrTimeout(); var bytes = Encoding.UTF8.GetBytes(message);
Assert.Equal(message, Encoding.UTF8.GetString(receivedData)); logger.LogInformation("Sending {length} byte message", bytes.Length);
} await connection.SendAsync(bytes, MessageType.Text).OrTimeout();
finally logger.LogInformation("Sent message", bytes.Length);
{
await connection.DisposeAsync(); var receiveData = new ReceiveData();
logger.LogInformation("Receiving message");
var receivedData = await receiveTcs.Task.OrTimeout();
Assert.Equal(message, Encoding.UTF8.GetString(receivedData));
logger.LogInformation("Completed receive");
}
finally
{
logger.LogInformation("Disposing Connection");
await connection.DisposeAsync().OrTimeout();
logger.LogInformation("Disposed Connection");
}
} }
} }
@ -150,4 +198,4 @@ namespace Microsoft.AspNetCore.SignalR.Tests
new object[] { TransportType.LongPolling } new object[] { TransportType.LongPolling }
}; };
} }
} }

View File

@ -1,4 +1,4 @@
// Copyright (c) .NET Foundation. All rights reserved. // Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using System; using System;
@ -9,14 +9,18 @@ using Microsoft.AspNetCore.Hosting;
using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging;
using Microsoft.AspNetCore.Builder; using Microsoft.AspNetCore.Builder;
using Microsoft.Extensions.Logging.Testing;
using Xunit.Abstractions;
namespace Microsoft.AspNetCore.SignalR.Tests namespace Microsoft.AspNetCore.SignalR.Tests
{ {
public class ServerFixture : IDisposable public class ServerFixture : IDisposable
{ {
private ILoggerFactory _loggerFactory; private ILoggerFactory _loggerFactory;
private ILogger _logger;
private IWebHost host; private IWebHost host;
private IApplicationLifetime lifetime; private IApplicationLifetime lifetime;
private readonly IDisposable _logToken;
public string BaseUrl => "http://localhost:3000"; public string BaseUrl => "http://localhost:3000";
@ -24,17 +28,10 @@ namespace Microsoft.AspNetCore.SignalR.Tests
public ServerFixture() public ServerFixture()
{ {
_loggerFactory = new LoggerFactory(); var testLog = AssemblyTestLog.ForAssembly(typeof(ServerFixture).Assembly);
_logToken = testLog.StartTestLog(null, typeof(ServerFixture).FullName, out _loggerFactory, "ServerFixture");
_logger = _loggerFactory.CreateLogger<ServerFixture>();
var _verbose = string.Equals(Environment.GetEnvironmentVariable("SIGNALR_TESTS_VERBOSE"), "1");
if (_verbose)
{
_loggerFactory.AddConsole(LogLevel.Debug);
}
if (Debugger.IsAttached)
{
_loggerFactory.AddDebug();
}
StartServer(); StartServer();
} }
@ -64,7 +61,7 @@ namespace Microsoft.AspNetCore.SignalR.Tests
.Build(); .Build();
var t = Task.Run(() => host.Start()); var t = Task.Run(() => host.Start());
Console.WriteLine("Starting test server..."); _logger.LogInformation("Starting test server...");
lifetime = host.Services.GetRequiredService<IApplicationLifetime>(); lifetime = host.Services.GetRequiredService<IApplicationLifetime>();
if (!lifetime.ApplicationStarted.WaitHandle.WaitOne(TimeSpan.FromSeconds(5))) if (!lifetime.ApplicationStarted.WaitHandle.WaitOne(TimeSpan.FromSeconds(5)))
{ {
@ -75,10 +72,18 @@ namespace Microsoft.AspNetCore.SignalR.Tests
} }
throw new TimeoutException("Timed out waiting for application to start."); throw new TimeoutException("Timed out waiting for application to start.");
} }
_logger.LogInformation("Test Server started");
lifetime.ApplicationStopped.Register(() =>
{
_logger.LogInformation("Test server shut down");
_logToken.Dispose();
});
} }
public void Dispose() public void Dispose()
{ {
_logger.LogInformation("Shutting down test server");
host.Dispose(); host.Dispose();
} }
} }