From fc4e64de38452ccab7442f0b42a540649fe15ec9 Mon Sep 17 00:00:00 2001 From: Nate McMaster Date: Tue, 6 Nov 2018 16:58:30 -0800 Subject: [PATCH] Reorganize source code in preparation to move into aspnet/Extensions Prior to reorganization, this source code was found in https://github.com/aspnet/Logging/tree/f7d8e4e0537eaab54dcf28c2b148b82688a3d62d --- ...AzureAppServicesLoggerFactoryExtensions.cs | 3 ++ .../src/AzureFileLoggerOptions.cs | 7 +-- .../src/Internal/BatchingLogger.cs | 17 ++++++- .../src/Internal/BatchingLoggerOptions.cs | 6 +++ .../src/Internal/BatchingLoggerProvider.cs | 14 +++++- .../test/BatchingLoggerProviderTests.cs | 38 +++++++++++++-- src/Logging/Logging.Testing/src/ITestSink.cs | 4 ++ .../src/LoggedTest/LoggedTestBase.cs | 4 +- src/Logging/Logging.Testing/src/TestSink.cs | 6 +++ .../src/Xunit/LogLevelAttribute.cs | 2 +- .../test/LoggedTestXunitTests.cs | 46 ++++++++++++++++++- .../test/Properties/AssemlyInfo.cs | 4 ++ 12 files changed, 139 insertions(+), 12 deletions(-) create mode 100644 src/Logging/Logging.Testing/test/Properties/AssemlyInfo.cs diff --git a/src/Logging/Logging.AzureAppServices/src/AzureAppServicesLoggerFactoryExtensions.cs b/src/Logging/Logging.AzureAppServices/src/AzureAppServicesLoggerFactoryExtensions.cs index a0e73027fb..ea558a0974 100644 --- a/src/Logging/Logging.AzureAppServices/src/AzureAppServicesLoggerFactoryExtensions.cs +++ b/src/Logging/Logging.AzureAppServices/src/AzureAppServicesLoggerFactoryExtensions.cs @@ -7,6 +7,7 @@ using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.DependencyInjection.Extensions; using Microsoft.Extensions.Logging.AzureAppServices; using Microsoft.Extensions.Logging.AzureAppServices.Internal; +using Microsoft.Extensions.Logging.Configuration; using Microsoft.Extensions.Options; using static Microsoft.Extensions.DependencyInjection.ServiceDescriptor; @@ -55,6 +56,7 @@ namespace Microsoft.Extensions.Logging services.AddSingleton>(new FileLoggerConfigureOptions(config, context)); services.AddSingleton>( new ConfigurationChangeTokenSource(config)); + LoggerProviderOptions.RegisterProviderOptions(builder.Services); } if (addedBlobLogger) @@ -63,6 +65,7 @@ namespace Microsoft.Extensions.Logging services.AddSingleton>(new BlobLoggerConfigureOptions(config, context)); services.AddSingleton>( new ConfigurationChangeTokenSource(config)); + LoggerProviderOptions.RegisterProviderOptions(builder.Services); } return builder; diff --git a/src/Logging/Logging.AzureAppServices/src/AzureFileLoggerOptions.cs b/src/Logging/Logging.AzureAppServices/src/AzureFileLoggerOptions.cs index 47795d9954..d9b8e89198 100644 --- a/src/Logging/Logging.AzureAppServices/src/AzureFileLoggerOptions.cs +++ b/src/Logging/Logging.AzureAppServices/src/AzureFileLoggerOptions.cs @@ -51,8 +51,9 @@ namespace Microsoft.Extensions.Logging.AzureAppServices } /// - /// Gets or sets a strictly positive value representing the maximum retained file count or null for no limit. - /// Defaults to 2. + /// Gets or sets a string representing the prefix of the file name used to store the logging information. + /// The current date, in the format YYYYMMDD will be added after the given value. + /// Defaults to diagnostics-. /// public string FileName { @@ -69,4 +70,4 @@ namespace Microsoft.Extensions.Logging.AzureAppServices internal string LogDirectory { get; set; } } -} \ No newline at end of file +} diff --git a/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLogger.cs b/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLogger.cs index 2cfb26582f..e207fbf2a2 100644 --- a/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLogger.cs +++ b/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLogger.cs @@ -40,7 +40,22 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal builder.Append(logLevel.ToString()); builder.Append("] "); builder.Append(_category); - builder.Append(": "); + + var scopeProvider = _provider.ScopeProvider; + if (scopeProvider != null) + { + scopeProvider.ForEachScope((scope, stringBuilder) => + { + stringBuilder.Append(" => ").Append(scope); + }, builder); + + builder.AppendLine(":"); + } + else + { + builder.Append(": "); + } + builder.AppendLine(formatter(state, exception)); if (exception != null) diff --git a/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerOptions.cs b/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerOptions.cs index fbbb5cfd08..89a8f2a1e7 100644 --- a/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerOptions.cs +++ b/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerOptions.cs @@ -66,5 +66,11 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal /// Gets or sets value indicating if logger accepts and queues writes. /// public bool IsEnabled { get; set; } + + /// + /// Gets or sets a value indicating whether scopes should be included in the message. + /// Defaults to false. + /// + public bool IncludeScopes { get; set; } = false; } } \ No newline at end of file diff --git a/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerProvider.cs b/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerProvider.cs index 79720c5531..c507b6e671 100644 --- a/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerProvider.cs +++ b/src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerProvider.cs @@ -10,7 +10,7 @@ using Microsoft.Extensions.Options; namespace Microsoft.Extensions.Logging.AzureAppServices.Internal { - public abstract class BatchingLoggerProvider: ILoggerProvider + public abstract class BatchingLoggerProvider: ILoggerProvider, ISupportExternalScope { private readonly List _currentBatch = new List(); private readonly TimeSpan _interval; @@ -22,6 +22,11 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal private Task _outputTask; private CancellationTokenSource _cancellationTokenSource; + private bool _includeScopes; + private IExternalScopeProvider _scopeProvider; + + internal IExternalScopeProvider ScopeProvider => _includeScopes ? _scopeProvider : null; + protected BatchingLoggerProvider(IOptionsMonitor options) { // NOTE: Only IsEnabled is monitored @@ -50,6 +55,8 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal { var oldIsEnabled = IsEnabled; IsEnabled = options.IsEnabled; + _includeScopes = options.IncludeScopes; + if (oldIsEnabled != IsEnabled) { if (IsEnabled) @@ -159,5 +166,10 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal { return new BatchingLogger(this, categoryName); } + + void ISupportExternalScope.SetScopeProvider(IExternalScopeProvider scopeProvider) + { + _scopeProvider = scopeProvider; + } } } \ No newline at end of file diff --git a/src/Logging/Logging.AzureAppServices/test/BatchingLoggerProviderTests.cs b/src/Logging/Logging.AzureAppServices/test/BatchingLoggerProviderTests.cs index 42cefe99df..0d4e1b85e0 100644 --- a/src/Logging/Logging.AzureAppServices/test/BatchingLoggerProviderTests.cs +++ b/src/Logging/Logging.AzureAppServices/test/BatchingLoggerProviderTests.cs @@ -4,6 +4,7 @@ using System; using System.Collections.Generic; using System.Linq; +using System.Text.RegularExpressions; using System.Threading; using System.Threading.Tasks; using Microsoft.Extensions.Logging.AzureAppServices.Internal; @@ -13,8 +14,9 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Test { public class BatchingLoggerProviderTests { - DateTimeOffset _timestampOne = new DateTimeOffset(2016, 05, 04, 03, 02, 01, TimeSpan.Zero); - string _nl = Environment.NewLine; + private DateTimeOffset _timestampOne = new DateTimeOffset(2016, 05, 04, 03, 02, 01, TimeSpan.Zero); + private string _nl = Environment.NewLine; + private Regex _timeStampRegex = new Regex(@"^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3} .\d{2}:\d{2} "); [Fact] public async Task LogsInIntervals() @@ -34,6 +36,33 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Test Assert.Equal("2016-05-04 04:02:01.000 +00:00 [Error] Cat: Error message" + _nl, provider.Batches[0][1].Message); } + [Fact] + public async Task IncludesScopes() + { + var provider = new TestBatchingLoggingProvider(includeScopes: true); + var factory = new LoggerFactory(new [] { provider }); + var logger = factory.CreateLogger("Cat"); + + await provider.IntervalControl.Pause; + + using (logger.BeginScope("Scope")) + { + using (logger.BeginScope("Scope2")) + { + logger.Log(LogLevel.Information, 0, "Info message", null, (state, ex) => state); + } + } + + provider.IntervalControl.Resume(); + await provider.IntervalControl.Pause; + + Assert.Matches(_timeStampRegex, provider.Batches[0][0].Message); + Assert.EndsWith( + " [Information] Cat => Scope => Scope2:" + _nl + + "Info message" + _nl, + provider.Batches[0][0].Message); + } + [Fact] public async Task RespectsBatchSize() { @@ -85,13 +114,14 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Test public List Batches { get; } = new List(); public ManualIntervalControl IntervalControl { get; } = new ManualIntervalControl(); - public TestBatchingLoggingProvider(TimeSpan? interval = null, int? maxBatchSize = null, int? maxQueueSize = null) + public TestBatchingLoggingProvider(TimeSpan? interval = null, int? maxBatchSize = null, int? maxQueueSize = null, bool includeScopes = false) : base(new OptionsWrapperMonitor(new BatchingLoggerOptions { FlushPeriod = interval ?? TimeSpan.FromSeconds(1), BatchSize = maxBatchSize, BackgroundQueueSize = maxQueueSize, - IsEnabled = true + IsEnabled = true, + IncludeScopes = includeScopes })) { } diff --git a/src/Logging/Logging.Testing/src/ITestSink.cs b/src/Logging/Logging.Testing/src/ITestSink.cs index bd2d1955ae..8b0bef5033 100644 --- a/src/Logging/Logging.Testing/src/ITestSink.cs +++ b/src/Logging/Logging.Testing/src/ITestSink.cs @@ -5,6 +5,10 @@ namespace Microsoft.Extensions.Logging.Testing { public interface ITestSink { + event Action MessageLogged; + + event Action ScopeStarted; + Func WriteEnabled { get; set; } Func BeginEnabled { get; set; } diff --git a/src/Logging/Logging.Testing/src/LoggedTest/LoggedTestBase.cs b/src/Logging/Logging.Testing/src/LoggedTest/LoggedTestBase.cs index f714a632a4..c3a4e78931 100644 --- a/src/Logging/Logging.Testing/src/LoggedTest/LoggedTestBase.cs +++ b/src/Logging/Logging.Testing/src/LoggedTest/LoggedTestBase.cs @@ -51,7 +51,9 @@ namespace Microsoft.Extensions.Logging.Testing TestOutputHelper = testOutputHelper; var classType = GetType(); - var logLevelAttribute = methodInfo.GetCustomAttribute(); + var logLevelAttribute = methodInfo.GetCustomAttribute() + ?? methodInfo.DeclaringType.GetCustomAttribute() + ?? methodInfo.DeclaringType.Assembly.GetCustomAttribute(); var testName = testMethodArguments.Aggregate(methodInfo.Name, (a, b) => $"{a}-{(b ?? "null")}"); var useShortClassName = methodInfo.DeclaringType.GetCustomAttribute() diff --git a/src/Logging/Logging.Testing/src/TestSink.cs b/src/Logging/Logging.Testing/src/TestSink.cs index f67cab5648..cc9c1ce7bc 100644 --- a/src/Logging/Logging.Testing/src/TestSink.cs +++ b/src/Logging/Logging.Testing/src/TestSink.cs @@ -30,12 +30,17 @@ namespace Microsoft.Extensions.Logging.Testing public IProducerConsumerCollection Writes { get => _writes; set => _writes = new ConcurrentQueue(value); } + public event Action MessageLogged; + + public event Action ScopeStarted; + public void Write(WriteContext context) { if (WriteEnabled == null || WriteEnabled(context)) { _writes.Enqueue(context); } + MessageLogged?.Invoke(context); } public void Begin(BeginScopeContext context) @@ -44,6 +49,7 @@ namespace Microsoft.Extensions.Logging.Testing { _scopes.Enqueue(context); } + ScopeStarted?.Invoke(context); } public static bool EnableWithTypeName(WriteContext context) diff --git a/src/Logging/Logging.Testing/src/Xunit/LogLevelAttribute.cs b/src/Logging/Logging.Testing/src/Xunit/LogLevelAttribute.cs index 9f6f621374..5de51cfe91 100644 --- a/src/Logging/Logging.Testing/src/Xunit/LogLevelAttribute.cs +++ b/src/Logging/Logging.Testing/src/Xunit/LogLevelAttribute.cs @@ -5,7 +5,7 @@ using System; namespace Microsoft.Extensions.Logging.Testing { - [AttributeUsage(AttributeTargets.Method, AllowMultiple = false)] + [AttributeUsage(AttributeTargets.Method | AttributeTargets.Class | AttributeTargets.Assembly, AllowMultiple = false)] public class LogLevelAttribute : Attribute { public LogLevelAttribute(LogLevel logLevel) diff --git a/src/Logging/Logging.Testing/test/LoggedTestXunitTests.cs b/src/Logging/Logging.Testing/test/LoggedTestXunitTests.cs index d1d8581193..507453a242 100644 --- a/src/Logging/Logging.Testing/test/LoggedTestXunitTests.cs +++ b/src/Logging/Logging.Testing/test/LoggedTestXunitTests.cs @@ -1,6 +1,7 @@ // 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. +using System.Linq; using System.Reflection; using Microsoft.AspNetCore.Testing.xunit; using Microsoft.Extensions.DependencyInjection; @@ -9,6 +10,7 @@ using Xunit.Abstractions; namespace Microsoft.Extensions.Logging.Testing.Tests { + [LogLevel(LogLevel.Debug)] [ShortClassName] public class LoggedTestXunitTests : TestLoggedTest { @@ -75,7 +77,7 @@ namespace Microsoft.Extensions.Logging.Testing.Tests [Fact] [LogLevel(LogLevel.Information)] - public void LoggedFactFilteredByLogLevel() + public void LoggedFactFilteredByMethodLogLevel() { Logger.LogInformation("Information"); Logger.LogDebug("Debug"); @@ -85,6 +87,17 @@ namespace Microsoft.Extensions.Logging.Testing.Tests Assert.Equal("Information", message.Formatter(message.State, null)); } + [Fact] + public void LoggedFactFilteredByClassLogLevel() + { + Logger.LogDebug("Debug"); + Logger.LogTrace("Trace"); + + var message = Assert.Single(TestSink.Writes); + Assert.Equal(LogLevel.Debug, message.LogLevel); + Assert.Equal("Debug", message.Formatter(message.State, null)); + } + [Theory] [InlineData("Hello world")] [LogLevel(LogLevel.Information)] @@ -129,6 +142,37 @@ namespace Microsoft.Extensions.Logging.Testing.Tests { Assert.True(SetupInvoked); } + + [Fact] + public void MessageWrittenEventInvoked() + { + WriteContext context = null; + TestSink.MessageLogged += ctx => context = ctx; + Logger.LogInformation("Information"); + Assert.Equal(TestSink.Writes.Single(), context); + } + + [Fact] + public void ScopeStartedEventInvoked() + { + BeginScopeContext context = null; + TestSink.ScopeStarted += ctx => context = ctx; + using (Logger.BeginScope("Scope")) {} + Assert.Equal(TestSink.Scopes.Single(), context); + } + } + + public class LoggedTestXunitLogLevelTests : LoggedTest + { + [Fact] + public void LoggedFactFilteredByAssemblyLogLevel() + { + Logger.LogTrace("Trace"); + + var message = Assert.Single(TestSink.Writes); + Assert.Equal(LogLevel.Trace, message.LogLevel); + Assert.Equal("Trace", message.Formatter(message.State, null)); + } } public class LoggedTestXunitInitializationTests : TestLoggedTest diff --git a/src/Logging/Logging.Testing/test/Properties/AssemlyInfo.cs b/src/Logging/Logging.Testing/test/Properties/AssemlyInfo.cs new file mode 100644 index 0000000000..63c2b71d23 --- /dev/null +++ b/src/Logging/Logging.Testing/test/Properties/AssemlyInfo.cs @@ -0,0 +1,4 @@ +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Testing; + +[assembly: LogLevel(LogLevel.Trace)]