From c714a8162400bf5dd0634da2fbe34d3e0213eb62 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Mon, 30 Apr 2018 16:51:17 -0700 Subject: [PATCH] Add connection id to sink log for unit tests (#2085) --- .../HubConnectionTests.cs | 22 +++++----- .../ServerFixture.cs | 43 +++++++++++++++++-- .../ServerLogScope.cs | 2 +- 3 files changed, 52 insertions(+), 15 deletions(-) diff --git a/test/Microsoft.AspNetCore.SignalR.Client.FunctionalTests/HubConnectionTests.cs b/test/Microsoft.AspNetCore.SignalR.Client.FunctionalTests/HubConnectionTests.cs index 3aad19ef2a..6c207f202f 100644 --- a/test/Microsoft.AspNetCore.SignalR.Client.FunctionalTests/HubConnectionTests.cs +++ b/test/Microsoft.AspNetCore.SignalR.Client.FunctionalTests/HubConnectionTests.cs @@ -32,6 +32,8 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests [Collection(HubConnectionTestsCollection.Name)] public class HubConnectionTests : VerifiableServerLoggedTest { + private const string DefaultHubDispatcherLoggerName = "SERVER Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher"; + public HubConnectionTests(ServerFixture serverFixture, ITestOutputHelper output) : base(serverFixture, output) { } @@ -430,7 +432,7 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests { bool ExpectedErrors(WriteContext writeContext) { - return writeContext.LoggerName == "Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher" && + return writeContext.LoggerName == DefaultHubDispatcherLoggerName && writeContext.EventId.Name == "FailedInvokingHubMethod"; } @@ -464,7 +466,7 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests { bool ExpectedErrors(WriteContext writeContext) { - return writeContext.LoggerName == "Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher" && + return writeContext.LoggerName == DefaultHubDispatcherLoggerName && writeContext.EventId.Name == "UnknownHubMethod"; } @@ -497,7 +499,7 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests { bool ExpectedErrors(WriteContext writeContext) { - return writeContext.LoggerName == "Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher" && + return writeContext.LoggerName == DefaultHubDispatcherLoggerName && writeContext.EventId.Name == "FailedInvokingHubMethod"; } @@ -530,7 +532,7 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests { bool ExpectedErrors(WriteContext writeContext) { - return writeContext.LoggerName == "Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher" && + return writeContext.LoggerName == DefaultHubDispatcherLoggerName && writeContext.EventId.Name == "FailedInvokingHubMethod"; } @@ -563,7 +565,7 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests { bool ExpectedErrors(WriteContext writeContext) { - return writeContext.LoggerName == "Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher" && + return writeContext.LoggerName == DefaultHubDispatcherLoggerName && writeContext.EventId.Name == "UnknownHubMethod"; } @@ -597,7 +599,7 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests { bool ExpectedErrors(WriteContext writeContext) { - return writeContext.LoggerName == "Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher" && + return writeContext.LoggerName == DefaultHubDispatcherLoggerName && writeContext.EventId.Name == "FailedInvokingHubMethod"; } @@ -632,7 +634,7 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests { bool ExpectedErrors(WriteContext writeContext) { - return writeContext.LoggerName == "Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher" && + return writeContext.LoggerName == DefaultHubDispatcherLoggerName && writeContext.EventId.Name == "FailedInvokingHubMethod"; } @@ -666,7 +668,7 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests { bool ExpectedErrors(WriteContext writeContext) { - return writeContext.LoggerName == "Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher" && + return writeContext.LoggerName == DefaultHubDispatcherLoggerName && writeContext.EventId.Name == "NonStreamingMethodCalledWithStream"; } @@ -699,7 +701,7 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests { bool ExpectedErrors(WriteContext writeContext) { - return writeContext.LoggerName == "Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher" && + return writeContext.LoggerName == DefaultHubDispatcherLoggerName && writeContext.EventId.Name == "StreamingMethodCalledWithInvoke"; } @@ -732,7 +734,7 @@ namespace Microsoft.AspNetCore.SignalR.Client.FunctionalTests { bool ExpectedErrors(WriteContext writeContext) { - return writeContext.LoggerName == "Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher" && + return writeContext.LoggerName == DefaultHubDispatcherLoggerName && writeContext.EventId.Name == "InvalidReturnValueFromStreamingMethod"; } diff --git a/test/Microsoft.AspNetCore.SignalR.Tests.Utils/ServerFixture.cs b/test/Microsoft.AspNetCore.SignalR.Tests.Utils/ServerFixture.cs index 952a29ef83..c4338ea723 100644 --- a/test/Microsoft.AspNetCore.SignalR.Tests.Utils/ServerFixture.cs +++ b/test/Microsoft.AspNetCore.SignalR.Tests.Utils/ServerFixture.cs @@ -12,6 +12,7 @@ using System.Text; using System.Threading.Tasks; using Microsoft.AspNetCore.Hosting; using Microsoft.AspNetCore.Hosting.Server.Features; +using Microsoft.AspNetCore.Server.Kestrel.Core.Internal; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Testing; @@ -165,9 +166,10 @@ namespace Microsoft.AspNetCore.SignalR.Tests } // TestSink doesn't seem to be thread-safe :(. - internal class LogSinkProvider : ILoggerProvider + internal class LogSinkProvider : ILoggerProvider, ISupportExternalScope { private readonly ConcurrentQueue _logs = new ConcurrentQueue(); + internal IExternalScopeProvider _scopeProvider; public event Action RecordLogged; @@ -186,7 +188,7 @@ namespace Microsoft.AspNetCore.SignalR.Tests { var record = new LogRecord( DateTime.Now, - new WriteContext() + new WriteContext { LoggerName = categoryName, LogLevel = logLevel, @@ -223,9 +225,42 @@ namespace Microsoft.AspNetCore.SignalR.Tests public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatter) { - _logSinkProvider.Log(_categoryName, logLevel, eventId, state, exception, formatter); + // Build the message outside of the formatter + // Serilog doesn't appear to use the formatter and just writes the state + var connectionId = GetConnectionId(); + + var sb = new StringBuilder(); + if (connectionId != null) + { + sb.Append(connectionId + " - "); + } + sb.Append(formatter(state, exception)); + var message = sb.ToString(); + + _logSinkProvider.Log(_categoryName, logLevel, eventId, message, exception, (s, ex) => s); + } + + private string GetConnectionId() + { + string connectionId = null; + _logSinkProvider._scopeProvider.ForEachScope((scope, s) => + { + if (scope is IReadOnlyList> logScope) + { + var id = logScope.FirstOrDefault(kv => kv.Key == "TransportConnectionId").Value as string; + if (id != null) + { + connectionId = id; + } + } + }, null); + return connectionId; } } - } + public void SetScopeProvider(IExternalScopeProvider scopeProvider) + { + _scopeProvider = scopeProvider; + } + } } diff --git a/test/Microsoft.AspNetCore.SignalR.Tests.Utils/ServerLogScope.cs b/test/Microsoft.AspNetCore.SignalR.Tests.Utils/ServerLogScope.cs index 8ca3281e98..1b4ff4e05c 100644 --- a/test/Microsoft.AspNetCore.SignalR.Tests.Utils/ServerLogScope.cs +++ b/test/Microsoft.AspNetCore.SignalR.Tests.Utils/ServerLogScope.cs @@ -50,7 +50,7 @@ namespace Microsoft.AspNetCore.SignalR.Tests lock (_lock) { // Create (or get) a logger with the same name as the server logger - logger = _serverLoggers.GetOrAdd(write.LoggerName, loggerName => _loggerFactory.CreateLogger(loggerName)); + logger = _serverLoggers.GetOrAdd(write.LoggerName, loggerName => _loggerFactory.CreateLogger("SERVER " + loggerName)); } logger.Log(write.LogLevel, write.EventId, write.State, write.Exception, write.Formatter);