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

Reorganize source code in preparation to move into aspnet/Extensions 

Prior to reorganization, this source code was found in 5381f42ded
This commit is contained in:
Nate McMaster 2018-11-06 15:28:23 -08:00
parent 018907bec0
commit 08375cd15c
22 changed files with 661 additions and 197 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
src/Logging/Logging.AzureAppServices/src/AzureAppServicesDiagnosticsSettings.cs
View File

@ -8,6 +8,7 @@ namespace Microsoft.Extensions.Logging.AzureAppServices
/// <summary>
/// Settings for Azure diagnostics logging.
/// </summary>
[Obsolete("This type is obsolete and will be removed in a future version. The recommended alternative is AzureBlobLoggerOptions.")]
public class AzureAppServicesDiagnosticsSettings
{
private TimeSpan _blobCommitPeriod = TimeSpan.FromSeconds(5);

3
src/Logging/Logging.AzureAppServices/src/AzureAppServicesLoggerFactoryExtensions.cs
View File

@ -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;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.DependencyInjection.Extensions;
@ -94,6 +95,7 @@ namespace Microsoft.Extensions.Logging
/// Adds an Azure Web Apps diagnostics logger.
/// </summary>
/// <param name="factory">The extension method argument</param>
[Obsolete("This method is obsolete and will be removed in a future version. The recommended alternative is AddAzureWebAppDiagnostics(this ILoggingBuilder builder).")]
public static ILoggerFactory AddAzureWebAppDiagnostics(this ILoggerFactory factory)
{
return AddAzureWebAppDiagnostics(factory, new AzureAppServicesDiagnosticsSettings());
@ -104,6 +106,7 @@ namespace Microsoft.Extensions.Logging
/// </summary>
/// <param name="factory">The extension method argument</param>
/// <param name="settings">The setting object to configure loggers.</param>
[Obsolete("This method is obsolete and will be removed in a future version. The recommended alternative is AddAzureWebAppDiagnostics(this ILoggingBuilder builder).")]
public static ILoggerFactory AddAzureWebAppDiagnostics(this ILoggerFactory factory, AzureAppServicesDiagnosticsSettings settings)
{
var context = WebAppContext.Default;

5
src/Logging/Logging.AzureAppServices/src/AzureBlobLoggerOptions.cs
View File

@ -11,11 +11,6 @@ namespace Microsoft.Extensions.Logging.AzureAppServices
/// </summary>
public class AzureBlobLoggerOptions: BatchingLoggerOptions
{
public AzureBlobLoggerOptions()
{
BatchSize = 32;
}
private string _blobName = "applicationLog.txt";
/// <summary>

7
src/Logging/Logging.AzureAppServices/src/Internal/BatchingLoggerOptions.cs
View File

@ -7,8 +7,8 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal
{
public class BatchingLoggerOptions
{
private int? _batchSize = 32;
private int? _backgroundQueueSize;
private int? _batchSize;
private int? _backgroundQueueSize = 1000;
private TimeSpan _flushPeriod = TimeSpan.FromSeconds(1);
/// <summary>
@ -30,7 +30,7 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal
/// <summary>
/// Gets or sets the maximum size of the background log message queue or null for no limit.
/// After maximum queue size is reached log event sink would start blocking.
/// Defaults to <c>null</c>.
/// Defaults to <c>1000</c>.
/// </summary>
public int? BackgroundQueueSize
{
@ -48,6 +48,7 @@ namespace Microsoft.Extensions.Logging.AzureAppServices.Internal
/// <summary>
/// Gets or sets a maximum number of events to include in a single batch or null for no limit.
/// </summary>
/// Defaults to <c>null</c>.
public int? BatchSize
{
get { return _batchSize; }

119
src/Logging/Logging.Testing/src/AssemblyTestLog.cs
View File

@ -8,10 +8,11 @@ using System.IO;
using System.Linq;
using System.Reflection;
using System.Runtime.CompilerServices;
using System.Runtime.InteropServices;
using System.Text;
using Microsoft.Extensions.DependencyInjection;
using Serilog;
using Serilog.Core;
using Serilog.Events;
using Serilog.Extensions.Logging;
using Xunit.Abstractions;
@ -19,7 +20,6 @@ namespace Microsoft.Extensions.Logging.Testing
{
public class AssemblyTestLog : IDisposable
{
public static readonly string OutputDirectoryEnvironmentVariableName = "ASPNETCORE_TEST_LOG_DIR";
private static readonly string MaxPathLengthEnvironmentVariableName = "ASPNETCORE_TEST_LOG_MAXPATH";
private static readonly string LogFileExtension = ".log";
private static readonly int MaxPathLength = GetMaxPathLength();
@ -38,7 +38,7 @@ namespace Microsoft.Extensions.Logging.Testing
private readonly ILoggerFactory _globalLoggerFactory;
private readonly ILogger _globalLogger;
private readonly string _baseDirectory;
private readonly string _assemblyName;
private readonly Assembly _assembly;
private readonly IServiceProvider _serviceProvider;
private static int GetMaxPathLength()
@ -48,12 +48,12 @@ namespace Microsoft.Extensions.Logging.Testing
return string.IsNullOrEmpty(maxPathString) ? defaultMaxPath : int.Parse(maxPathString);
}
private AssemblyTestLog(ILoggerFactory globalLoggerFactory, ILogger globalLogger, string baseDirectory, string assemblyName, IServiceProvider serviceProvider)
private AssemblyTestLog(ILoggerFactory globalLoggerFactory, ILogger globalLogger, string baseDirectory, Assembly assembly, IServiceProvider serviceProvider)
{
_globalLoggerFactory = globalLoggerFactory;
_globalLogger = globalLogger;
_baseDirectory = baseDirectory;
_assemblyName = assemblyName;
_assembly = assembly;
_serviceProvider = serviceProvider;
}
@ -61,11 +61,12 @@ namespace Microsoft.Extensions.Logging.Testing
StartTestLog(output, className, out loggerFactory, LogLevel.Debug, testName);
public IDisposable StartTestLog(ITestOutputHelper output, string className, out ILoggerFactory loggerFactory, LogLevel minLogLevel, [CallerMemberName] string testName = null) =>
StartTestLog(output, className, out loggerFactory, minLogLevel, out var _, testName);
StartTestLog(output, className, out loggerFactory, minLogLevel, out var _, out var _, testName);
internal IDisposable StartTestLog(ITestOutputHelper output, string className, out ILoggerFactory loggerFactory, LogLevel minLogLevel, out string resolvedTestName, [CallerMemberName] string testName = null)
internal IDisposable StartTestLog(ITestOutputHelper output, string className, out ILoggerFactory loggerFactory, LogLevel minLogLevel, out string resolvedTestName, out string logOutputDirectory, [CallerMemberName] string testName = null)
{
var serviceProvider = CreateLoggerServices(output, className, minLogLevel, out resolvedTestName, testName);
var logStart = DateTimeOffset.UtcNow;
var serviceProvider = CreateLoggerServices(output, className, minLogLevel, out resolvedTestName, out logOutputDirectory, testName, logStart);
var factory = serviceProvider.GetRequiredService<ILoggerFactory>();
loggerFactory = factory;
var logger = loggerFactory.CreateLogger("TestLifetime");
@ -75,7 +76,7 @@ namespace Microsoft.Extensions.Logging.Testing
var scope = logger.BeginScope("Test: {testName}", testName);
_globalLogger.LogInformation("Starting test {testName}", testName);
logger.LogInformation("Starting test {testName}", testName);
logger.LogInformation("Starting test {testName} at {logStart}", testName, logStart.ToString("s"));
return new Disposable(() =>
{
@ -88,36 +89,39 @@ namespace Microsoft.Extensions.Logging.Testing
});
}
public ILoggerFactory CreateLoggerFactory(ITestOutputHelper output, string className, [CallerMemberName] string testName = null) =>
CreateLoggerFactory(output, className, LogLevel.Trace, testName);
public ILoggerFactory CreateLoggerFactory(ITestOutputHelper output, string className, [CallerMemberName] string testName = null, DateTimeOffset? logStart = null)
=> CreateLoggerFactory(output, className, LogLevel.Trace, testName, logStart);
public ILoggerFactory CreateLoggerFactory(ITestOutputHelper output, string className, LogLevel minLogLevel, [CallerMemberName] string testName = null)
{
return CreateLoggerServices(output, className, minLogLevel, out var _, testName).GetRequiredService<ILoggerFactory>();
}
public ILoggerFactory CreateLoggerFactory(ITestOutputHelper output, string className, LogLevel minLogLevel, [CallerMemberName] string testName = null, DateTimeOffset? logStart = null)
=> CreateLoggerServices(output, className, minLogLevel, out var _, out var _, testName, logStart).GetRequiredService<ILoggerFactory>();
public IServiceProvider CreateLoggerServices(ITestOutputHelper output, string className, LogLevel minLogLevel, out string normalizedTestName, [CallerMemberName] string testName = null)
public IServiceProvider CreateLoggerServices(ITestOutputHelper output, string className, LogLevel minLogLevel, out string normalizedTestName, [CallerMemberName] string testName = null, DateTimeOffset? logStart = null)
=> CreateLoggerServices(output, className, minLogLevel, out normalizedTestName, out var _, testName, logStart);
public IServiceProvider CreateLoggerServices(ITestOutputHelper output, string className, LogLevel minLogLevel, out string normalizedTestName, out string logOutputDirectory, [CallerMemberName] string testName = null, DateTimeOffset? logStart = null)
{
normalizedTestName = string.Empty;
logOutputDirectory = string.Empty;
var assemblyName = _assembly.GetName().Name;
// Try to shorten the class name using the assembly name
if (className.StartsWith(_assemblyName + "."))
if (className.StartsWith(assemblyName + "."))
{
className = className.Substring(_assemblyName.Length + 1);
className = className.Substring(assemblyName.Length + 1);
}
SerilogLoggerProvider serilogLoggerProvider = null;
if (!string.IsNullOrEmpty(_baseDirectory))
{
var testOutputDirectory = Path.Combine(GetAssemblyBaseDirectory(_assemblyName, _baseDirectory), className);
logOutputDirectory = Path.Combine(GetAssemblyBaseDirectory(_baseDirectory, _assembly), className);
testName = RemoveIllegalFileChars(testName);
if (testOutputDirectory.Length + testName.Length + LogFileExtension.Length >= MaxPathLength)
if (logOutputDirectory.Length + testName.Length + LogFileExtension.Length >= MaxPathLength)
{
_globalLogger.LogWarning($"Test name {testName} is too long. Please shorten test name.");
// Shorten the test name by removing the middle portion of the testname
var testNameLength = MaxPathLength - testOutputDirectory.Length - LogFileExtension.Length;
var testNameLength = MaxPathLength - logOutputDirectory.Length - LogFileExtension.Length;
if (testNameLength <= 0)
{
@ -129,7 +133,7 @@ namespace Microsoft.Extensions.Logging.Testing
_globalLogger.LogWarning($"To prevent long paths test name was shortened to {testName}.");
}
var testOutputFile = Path.Combine(testOutputDirectory, $"{testName}{LogFileExtension}");
var testOutputFile = Path.Combine(logOutputDirectory, $"{testName}{LogFileExtension}");
if (File.Exists(testOutputFile))
{
@ -137,7 +141,7 @@ namespace Microsoft.Extensions.Logging.Testing
for (var i = 0; i < 1000; i++)
{
testOutputFile = Path.Combine(testOutputDirectory, $"{testName}.{i}{LogFileExtension}");
testOutputFile = Path.Combine(logOutputDirectory, $"{testName}.{i}{LogFileExtension}");
if (!File.Exists(testOutputFile))
{
@ -149,7 +153,7 @@ namespace Microsoft.Extensions.Logging.Testing
}
normalizedTestName = testName;
serilogLoggerProvider = ConfigureFileLogging(testOutputFile);
serilogLoggerProvider = ConfigureFileLogging(testOutputFile, logStart);
}
var serviceCollection = new ServiceCollection();
@ -159,7 +163,7 @@ namespace Microsoft.Extensions.Logging.Testing
if (output != null)
{
builder.AddXunit(output, minLogLevel);
builder.AddXunit(output, minLogLevel, logStart);
}
if (serilogLoggerProvider != null)
@ -172,14 +176,19 @@ namespace Microsoft.Extensions.Logging.Testing
return serviceCollection.BuildServiceProvider();
}
// For back compat
public static AssemblyTestLog Create(string assemblyName, string baseDirectory)
=> Create(Assembly.Load(new AssemblyName(assemblyName)), baseDirectory);
public static AssemblyTestLog Create(Assembly assembly, string baseDirectory)
{
var logStart = DateTimeOffset.UtcNow;
SerilogLoggerProvider serilogLoggerProvider = null;
var globalLogDirectory = GetAssemblyBaseDirectory(assemblyName, baseDirectory);
var globalLogDirectory = GetAssemblyBaseDirectory(baseDirectory, assembly);
if (!string.IsNullOrEmpty(globalLogDirectory))
{
var globalLogFileName = Path.Combine(globalLogDirectory, "global.log");
serilogLoggerProvider = ConfigureFileLogging(globalLogFileName);
serilogLoggerProvider = ConfigureFileLogging(globalLogFileName, logStart);
}
var serviceCollection = new ServiceCollection();
@ -200,8 +209,11 @@ namespace Microsoft.Extensions.Logging.Testing
var loggerFactory = serviceProvider.GetRequiredService<ILoggerFactory>();
var logger = loggerFactory.CreateLogger("GlobalTestLog");
logger.LogInformation($"Global Test Logging initialized. Set the '{OutputDirectoryEnvironmentVariableName}' Environment Variable in order to create log files on disk.");
return new AssemblyTestLog(loggerFactory, logger, baseDirectory, assemblyName, serviceProvider);
logger.LogInformation("Global Test Logging initialized at {logStart}. "
+ "Configure the output directory via 'LoggingTestingFileLoggingDirectory' MSBuild property "
+ "or set 'LoggingTestingDisableFileLogging' to 'true' to disable file logging.",
logStart.ToString("s"));
return new AssemblyTestLog(loggerFactory, logger, baseDirectory, assembly, serviceProvider);
}
public static AssemblyTestLog ForAssembly(Assembly assembly)
@ -210,13 +222,13 @@ namespace Microsoft.Extensions.Logging.Testing
{
if (!_logs.TryGetValue(assembly, out var log))
{
var assemblyName = assembly.GetName().Name;
var baseDirectory = Environment.GetEnvironmentVariable(OutputDirectoryEnvironmentVariableName);
log = Create(assemblyName, baseDirectory);
var baseDirectory = GetFileLoggerAttribute(assembly).BaseDirectory;
log = Create(assembly, baseDirectory);
_logs[assembly] = log;
// Try to clear previous logs
var assemblyBaseDirectory = GetAssemblyBaseDirectory(assemblyName, baseDirectory);
var assemblyBaseDirectory = GetAssemblyBaseDirectory(baseDirectory, assembly);
if (Directory.Exists(assemblyBaseDirectory))
{
try
@ -230,16 +242,18 @@ namespace Microsoft.Extensions.Logging.Testing
}
}
private static string GetAssemblyBaseDirectory(string assemblyName, string baseDirectory)
{
if (!string.IsNullOrEmpty(baseDirectory))
{
return Path.Combine(baseDirectory, assemblyName, RuntimeInformation.FrameworkDescription.TrimStart('.'));
}
return string.Empty;
}
private static string GetAssemblyBaseDirectory(string baseDirectory, Assembly assembly)
=> string.IsNullOrEmpty(baseDirectory)
? string.Empty
: Path.Combine(baseDirectory, assembly.GetName().Name, GetFileLoggerAttribute(assembly).TFM);
private static SerilogLoggerProvider ConfigureFileLogging(string fileName)
private static TestFrameworkFileLoggerAttribute GetFileLoggerAttribute(Assembly assembly)
=> assembly.GetCustomAttribute<TestFrameworkFileLoggerAttribute>()
?? throw new InvalidOperationException($"No {nameof(TestFrameworkFileLoggerAttribute)} found on the assembly {assembly.GetName().Name}. "
+ "The attribute is added via msbuild properties of the Microsoft.Extensions.Logging.Testing. "
+ "Please ensure the msbuild property is imported or a direct reference to Microsoft.Extensions.Logging.Testing is added.");
private static SerilogLoggerProvider ConfigureFileLogging(string fileName, DateTimeOffset? logStart)
{
var dir = Path.GetDirectoryName(fileName);
if (!Directory.Exists(dir))
@ -254,8 +268,9 @@ namespace Microsoft.Extensions.Logging.Testing
var serilogger = new LoggerConfiguration()
.Enrich.FromLogContext()
.Enrich.With(new AssemblyLogTimestampOffsetEnricher(logStart))
.MinimumLevel.Verbose()
.WriteTo.File(fileName, outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{SourceContext}] [{Level}] {Message}{NewLine}{Exception}", flushToDiskInterval: TimeSpan.FromSeconds(1), shared: true)
.WriteTo.File(fileName, outputTemplate: "[{TimestampOffset}] [{SourceContext}] [{Level}] {Message:l}{NewLine}{Exception}", flushToDiskInterval: TimeSpan.FromSeconds(1), shared: true)
.CreateLogger();
return new SerilogLoggerProvider(serilogger, dispose: true);
}
@ -287,6 +302,24 @@ namespace Microsoft.Extensions.Logging.Testing
_globalLoggerFactory.Dispose();
}
private class AssemblyLogTimestampOffsetEnricher : ILogEventEnricher
{
private DateTimeOffset? _logStart;
public AssemblyLogTimestampOffsetEnricher(DateTimeOffset? logStart)
{
_logStart = logStart;
}
public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
=> logEvent.AddPropertyIfAbsent(
propertyFactory.CreateProperty(
"TimestampOffset",
_logStart.HasValue
? $"{(DateTimeOffset.UtcNow - _logStart.Value).TotalSeconds.ToString("N3")}s"
: DateTimeOffset.UtcNow.ToString("s")));
}
private class Disposable : IDisposable
{
private Action _action;

45
src/Logging/Logging.Testing/src/LoggedTest.cs
View File

@ -1,45 +0,0 @@
// 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;
using System.Reflection;
using System.Runtime.CompilerServices;
using Microsoft.Extensions.DependencyInjection;
using Xunit.Abstractions;
namespace Microsoft.Extensions.Logging.Testing
{
public abstract class LoggedTest
{
// Obsolete but keeping for back compat
public LoggedTest(ITestOutputHelper output = null)
{
TestOutputHelper = output;
}
// Internal for testing
internal string ResolvedTestMethodName { get; set; }
// Internal for testing
internal string ResolvedTestClassName { get; set; }
public ILogger Logger { get; set; }
public ILoggerFactory LoggerFactory { get; set; }
public ITestOutputHelper TestOutputHelper { get; set; }
public ITestSink TestSink { get; set; }
public void AddTestLogging(IServiceCollection services) => services.AddSingleton(LoggerFactory);
public IDisposable StartLog(out ILoggerFactory loggerFactory, [CallerMemberName] string testName = null) => StartLog(out loggerFactory, LogLevel.Information, testName);
public IDisposable StartLog(out ILoggerFactory loggerFactory, LogLevel minLogLevel, [CallerMemberName] string testName = null)
{
return AssemblyTestLog.ForAssembly(GetType().GetTypeInfo().Assembly).StartTestLog(TestOutputHelper, GetType().FullName, out loggerFactory, minLogLevel, testName);
}
public virtual void AdditionalSetup() { }
}
}

23
src/Logging/Logging.Testing/src/LoggedTest/ILoggedTest.cs Normal file
View File

@ -0,0 +1,23 @@
// 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;
using System.Reflection;
using Xunit.Abstractions;
namespace Microsoft.Extensions.Logging.Testing
{
public interface ILoggedTest : IDisposable
{
ILogger Logger { get; }
ILoggerFactory LoggerFactory { get; }
ITestOutputHelper TestOutputHelper { get; }
// For back compat
IDisposable StartLog(out ILoggerFactory loggerFactory, LogLevel minLogLevel, string testName);
void Initialize(MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper);
}
}

24
src/Logging/Logging.Testing/src/LoggedTest/LoggedTest.cs Normal file
View File

@ -0,0 +1,24 @@
// 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.Reflection;
using Xunit.Abstractions;
namespace Microsoft.Extensions.Logging.Testing
{
public class LoggedTest : LoggedTestBase
{
// Obsolete but keeping for back compat
public LoggedTest(ITestOutputHelper output = null) : base (output) { }
public ITestSink TestSink { get; set; }
public override void Initialize(MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper)
{
base.Initialize(methodInfo, testMethodArguments, testOutputHelper);
TestSink = new TestSink();
LoggerFactory.AddProvider(new TestLoggerProvider(TestSink));
}
}
}

82
src/Logging/Logging.Testing/src/LoggedTest/LoggedTestBase.cs Normal file
View File

@ -0,0 +1,82 @@
// 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;
using System.Linq;
using System.Reflection;
using System.Runtime.CompilerServices;
using Microsoft.Extensions.DependencyInjection;
using Xunit.Abstractions;
namespace Microsoft.Extensions.Logging.Testing
{
public class LoggedTestBase : ILoggedTest
{
private IDisposable _testLog;
// Obsolete but keeping for back compat
public LoggedTestBase(ITestOutputHelper output = null)
{
TestOutputHelper = output;
}
// Internal for testing
internal string ResolvedTestClassName { get; set; }
internal RetryContext RetryContext { get; set; }
public string ResolvedLogOutputDirectory { get; set; }
public string ResolvedTestMethodName { get; set; }
public ILogger Logger { get; set; }
public ILoggerFactory LoggerFactory { get; set; }
public ITestOutputHelper TestOutputHelper { get; set; }
public void AddTestLogging(IServiceCollection services) => services.AddSingleton(LoggerFactory);
// For back compat
public IDisposable StartLog(out ILoggerFactory loggerFactory, [CallerMemberName] string testName = null) => StartLog(out loggerFactory, LogLevel.Debug, testName);
// For back compat
public IDisposable StartLog(out ILoggerFactory loggerFactory, LogLevel minLogLevel, [CallerMemberName] string testName = null)
{
return AssemblyTestLog.ForAssembly(GetType().GetTypeInfo().Assembly).StartTestLog(TestOutputHelper, GetType().FullName, out loggerFactory, minLogLevel, testName);
}
public virtual void Initialize(MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper)
{
TestOutputHelper = testOutputHelper;
var classType = GetType();
var logLevelAttribute = methodInfo.GetCustomAttribute<LogLevelAttribute>();
var testName = testMethodArguments.Aggregate(methodInfo.Name, (a, b) => $"{a}-{(b ?? "null")}");
var useShortClassName = methodInfo.DeclaringType.GetCustomAttribute<ShortClassNameAttribute>()
?? methodInfo.DeclaringType.Assembly.GetCustomAttribute<ShortClassNameAttribute>();
// internal for testing
ResolvedTestClassName = useShortClassName == null ? classType.FullName : classType.Name;
_testLog = AssemblyTestLog
.ForAssembly(classType.GetTypeInfo().Assembly)
.StartTestLog(
TestOutputHelper,
ResolvedTestClassName,
out var loggerFactory,
logLevelAttribute?.LogLevel ?? LogLevel.Debug,
out var resolvedTestName,
out var logOutputDirectory,
testName);
ResolvedLogOutputDirectory = logOutputDirectory;
ResolvedTestMethodName = resolvedTestName;
LoggerFactory = loggerFactory;
Logger = loggerFactory.CreateLogger(classType);
}
public virtual void Dispose() => _testLog.Dispose();
}
}

18
src/Logging/Logging.Testing/src/RetryContext.cs Normal file
View File

@ -0,0 +1,18 @@
// 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;
namespace Microsoft.Extensions.Logging.Testing
{
public class RetryContext
{
internal int Limit { get; set; }
internal object TestClassInstance { get; set; }
internal string Reason { get; set; }
internal int CurrentIteration { get; set; }
}
}

20
src/Logging/Logging.Testing/src/TestFrameworkFileLoggerAttribute.cs Normal file
View File

@ -0,0 +1,20 @@
// 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;
namespace Microsoft.Extensions.Logging.Testing
{
[AttributeUsage(AttributeTargets.Assembly, AllowMultiple = false)]
public class TestFrameworkFileLoggerAttribute : Attribute
{
public TestFrameworkFileLoggerAttribute(string tfm, string baseDirectory = null)
{
TFM = tfm;
BaseDirectory = baseDirectory;
}
public string TFM { get; }
public string BaseDirectory { get; }
}
}

14
src/Logging/Logging.Testing/src/Xunit/LoggedConditionalTheoryDiscoverer.cs
View File

@ -32,6 +32,20 @@ namespace Microsoft.Extensions.Logging.Testing
object[] dataRow)
{
var skipReason = testMethod.EvaluateSkipConditions();
if (skipReason == null && dataRow?.Length > 0)
{
var obj = dataRow[0];
if (obj != null)
{
var type = obj.GetType();
var property = type.GetProperty("Skip");
if (property != null && property.PropertyType.Equals(typeof(string)))
{
skipReason = property.GetValue(obj) as string;
}
}
}
return skipReason != null
? base.CreateTestCasesForSkippedDataRow(discoveryOptions, testMethod, theoryAttribute, dataRow, skipReason)
: base.CreateTestCasesForDataRow(discoveryOptions, testMethod, theoryAttribute, dataRow);

2
src/Logging/Logging.Testing/src/Xunit/LoggedTestFrameworkDiscoverer.cs
View File

@ -37,7 +37,7 @@ namespace Microsoft.Extensions.Logging.Testing
IMessageBus messageBus,
ITestFrameworkDiscoveryOptions discoveryOptions)
{
if (typeof(LoggedTest).IsAssignableFrom(testMethod.TestClass.Class.ToRuntimeType()))
if (typeof(ILoggedTest).IsAssignableFrom(testMethod.TestClass.Class.ToRuntimeType()))
{
var factAttributes = testMethod.Method.GetCustomAttributes(typeof(FactAttribute));
if (factAttributes.Count() > 1)

81
src/Logging/Logging.Testing/src/Xunit/LoggedTestInvoker.cs
View File

@ -6,7 +6,6 @@ using System.Collections.Generic;
using System.Linq;
using System.Reflection;
using System.Threading;
using System.Threading.Tasks;
using Xunit.Abstractions;
using Xunit.Sdk;
@ -14,7 +13,8 @@ namespace Microsoft.Extensions.Logging.Testing
{
public class LoggedTestInvoker : XunitTestInvoker
{
private TestOutputHelper _output;
private readonly ITestOutputHelper _output;
private readonly RetryContext _retryContext;
public LoggedTestInvoker(
ITest test,
@ -25,73 +25,40 @@ namespace Microsoft.Extensions.Logging.Testing
object[] testMethodArguments,
IReadOnlyList<BeforeAfterTestAttribute> beforeAfterAttributes,
ExceptionAggregator aggregator,
CancellationTokenSource cancellationTokenSource)
CancellationTokenSource cancellationTokenSource,
ITestOutputHelper output,
RetryContext retryContext)
: base(test, messageBus, testClass, constructorArguments, testMethod, testMethodArguments, beforeAfterAttributes, aggregator, cancellationTokenSource)
{
}
protected override Task BeforeTestMethodInvokedAsync()
{
if (_output != null)
{
_output.Initialize(MessageBus, Test);
}
return base.BeforeTestMethodInvokedAsync();
}
protected override async Task AfterTestMethodInvokedAsync()
{
await base.AfterTestMethodInvokedAsync();
if (_output != null)
{
_output.Uninitialize();
}
_output = output;
_retryContext = retryContext;
}
protected override object CreateTestClass()
{
var testClass = base.CreateTestClass();
if (testClass is LoggedTest loggedTestClass)
(testClass as ILoggedTest).Initialize(
TestMethod,
TestMethodArguments,
_output ?? ConstructorArguments.SingleOrDefault(a => typeof(ITestOutputHelper).IsAssignableFrom(a.GetType())) as ITestOutputHelper);
if (testClass is LoggedTestBase loggedTestBase)
{
var classType = loggedTestClass.GetType();
var logLevelAttribute = TestMethod.GetCustomAttribute<LogLevelAttribute>() as LogLevelAttribute;
var testName = TestMethodArguments.Aggregate(TestMethod.Name, (a, b) => $"{a}-{(b ?? "null")}");
// Used for testing
loggedTestBase.RetryContext = _retryContext;
// Try resolving ITestOutputHelper from constructor arguments
loggedTestClass.TestOutputHelper = ConstructorArguments?.SingleOrDefault(a => typeof(ITestOutputHelper).IsAssignableFrom(a.GetType())) as ITestOutputHelper;
var useShortClassName = TestMethod.DeclaringType.GetCustomAttribute<ShortClassNameAttribute>()
?? TestMethod.DeclaringType.Assembly.GetCustomAttribute<ShortClassNameAttribute>();
var resolvedClassName = useShortClassName == null ? classType.FullName : classType.Name;
// None resolved so create a new one and retain a reference to it for initialization/uninitialization
if (loggedTestClass.TestOutputHelper == null)
if (_retryContext != null)
{
loggedTestClass.TestOutputHelper = _output = new TestOutputHelper();
// Log retry attempt as warning
if (_retryContext.CurrentIteration > 0)
{
loggedTestBase.Logger.LogWarning($"{TestMethod.Name} failed and retry conditions are met, re-executing. The reason for failure is {_retryContext.Reason}.");
}
// Save the test class instance for non-static predicates
_retryContext.TestClassInstance = testClass;
}
AssemblyTestLog
.ForAssembly(classType.GetTypeInfo().Assembly)
.StartTestLog(
loggedTestClass.TestOutputHelper,
resolvedClassName,
out var loggerFactory,
logLevelAttribute?.LogLevel ?? LogLevel.Trace,
out var resolvedTestName,
testName);
// internal for testing
loggedTestClass.ResolvedTestMethodName = resolvedTestName;
loggedTestClass.ResolvedTestClassName = resolvedClassName;
loggedTestClass.LoggerFactory = loggerFactory;
loggedTestClass.Logger = loggerFactory.CreateLogger(classType);
loggedTestClass.TestSink = new TestSink();
loggerFactory.AddProvider(new TestLoggerProvider(loggedTestClass.TestSink));
loggedTestClass.AdditionalSetup();
}
return testClass;

99
src/Logging/Logging.Testing/src/Xunit/LoggedTestRunner.cs
View File

@ -3,9 +3,13 @@
using System;
using System.Collections.Generic;
using System.Linq;
using System.Reflection;
using System.Runtime.InteropServices;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Testing.xunit;
using Microsoft.Extensions.Logging.Testing;
using Xunit.Abstractions;
using Xunit.Sdk;
@ -27,7 +31,100 @@ namespace Microsoft.Extensions.Logging.Testing
{
}
protected async override Task<Tuple<decimal, string>> InvokeTestAsync(ExceptionAggregator aggregator)
{
var testOutputHelper = ConstructorArguments.SingleOrDefault(a => typeof(TestOutputHelper).IsAssignableFrom(a.GetType())) as TestOutputHelper
?? new TestOutputHelper();
testOutputHelper.Initialize(MessageBus, Test);
var executionTime = await InvokeTestMethodAsync(aggregator, testOutputHelper);
var output = testOutputHelper.Output;
testOutputHelper.Uninitialize();
return Tuple.Create(executionTime, output);
}
protected override Task<decimal> InvokeTestMethodAsync(ExceptionAggregator aggregator)
=> new LoggedTestInvoker(Test, MessageBus, TestClass, ConstructorArguments, TestMethod, TestMethodArguments, BeforeAfterAttributes, aggregator, CancellationTokenSource).RunAsync();
=> InvokeTestMethodAsync(aggregator, null);
private async Task<decimal> InvokeTestMethodAsync(ExceptionAggregator aggregator, ITestOutputHelper output)
{
var retryAttribute = GetRetryAttribute(TestMethod);
if (!typeof(LoggedTestBase).IsAssignableFrom(TestClass) || retryAttribute == null)
{
return await new LoggedTestInvoker(Test, MessageBus, TestClass, ConstructorArguments, TestMethod, TestMethodArguments, BeforeAfterAttributes, aggregator, CancellationTokenSource, output, null).RunAsync();
}
var retryPredicateMethodName = retryAttribute.RetryPredicateName;
var retryPredicateMethod = TestClass.GetMethod(retryPredicateMethodName,
BindingFlags.Public | BindingFlags.NonPublic | BindingFlags.Instance | BindingFlags.Static,
null,
new Type[] { typeof(Exception) },
null)
?? throw new InvalidOperationException($"No valid static retry predicate method {retryPredicateMethodName} was found on the type {TestClass.FullName}.");
if (retryPredicateMethod.ReturnType != typeof(bool))
{
throw new InvalidOperationException($"Retry predicate method {retryPredicateMethodName} on {TestClass.FullName} does not return bool.");
}
var retryContext = new RetryContext()
{
Limit = retryAttribute.RetryLimit,
Reason = retryAttribute.RetryReason,
};
var retryAggregator = new ExceptionAggregator();
var loggedTestInvoker = new LoggedTestInvoker(Test, MessageBus, TestClass, ConstructorArguments, TestMethod, TestMethodArguments, BeforeAfterAttributes, retryAggregator, CancellationTokenSource, output, retryContext);
var totalTime = 0.0M;
do
{
retryAggregator.Clear();
totalTime += await loggedTestInvoker.RunAsync();
retryContext.CurrentIteration++;
}
while (retryAggregator.HasExceptions
&& retryContext.CurrentIteration < retryContext.Limit
&& (retryPredicateMethod.IsStatic
? (bool)retryPredicateMethod.Invoke(null, new object[] { retryAggregator.ToException() })
: (bool)retryPredicateMethod.Invoke(retryContext.TestClassInstance, new object[] { retryAggregator.ToException() }))
);
aggregator.Aggregate(retryAggregator);
return totalTime;
}
private RetryTestAttribute GetRetryAttribute(MethodInfo methodInfo)
{
var os = RuntimeInformation.IsOSPlatform(OSPlatform.OSX) ? OperatingSystems.MacOSX
: RuntimeInformation.IsOSPlatform(OSPlatform.Windows) ? OperatingSystems.Windows
: OperatingSystems.Linux;
var attributeCandidate = methodInfo.GetCustomAttribute<RetryTestAttribute>();
if (attributeCandidate != null && (attributeCandidate.OperatingSystems & os) != 0)
{
return attributeCandidate;
}
attributeCandidate = methodInfo.DeclaringType.GetCustomAttribute<RetryTestAttribute>();
if (attributeCandidate != null && (attributeCandidate.OperatingSystems & os) != 0)
{
return attributeCandidate;
}
attributeCandidate = methodInfo.DeclaringType.Assembly.GetCustomAttribute<RetryTestAttribute>();
if (attributeCandidate != null && (attributeCandidate.OperatingSystems & os) != 0)
{
return attributeCandidate;
}
return null;
}
}
}

68
src/Logging/Logging.Testing/src/Xunit/RetryTestAttribute.cs Normal file
View File

@ -0,0 +1,68 @@
// 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;
using System.ComponentModel;
using Microsoft.AspNetCore.Testing.xunit;
namespace Microsoft.Extensions.Logging.Testing
{
/// <summary>
/// WARNING: This attribute should only be used on well understood flaky test failures caused by external issues and should be removed once the underlying issues have been resolved.
/// This is not intended to be a long term solution to ensure passing of flaky tests but instead a method to improve test reliability without reducing coverage.
/// Issues should be filed to remove these attributes from affected tests as soon as the underlying issue is fixed.
/// </summary>
[EditorBrowsable(EditorBrowsableState.Never)]
[AttributeUsage(AttributeTargets.Method | AttributeTargets.Class, AllowMultiple = false)]
public class RetryTestAttribute : Attribute
{
/// <summary>
/// WARNING: This attribute should only be used on well understood flaky test failures caused by external issues and should be removed once the underlying issues have been resolved.
/// This is not intended to be a long term solution to ensure passing of flaky tests but instead a method to improve test reliability without reducing coverage.
/// Issues should be filed to remove these attributes from affected tests as soon as the underlying issue is fixed.
/// </summary>
/// <param name="retryPredicateName">The predicate of the format Func&lt;Exception,bool&gt; that is used to determine if the test should be retried</param>
/// <param name="retryReason">The reason for retrying the test</param>
/// <param name="retryLimit">The number of retries to attempt before failing the test, for most purposes this this should be kept at 2 to avoid excessive retries.</param>
public RetryTestAttribute(string retryPredicateName, string retryReason, int retryLimit = 2)
: this(retryPredicateName, retryReason, OperatingSystems.Linux | OperatingSystems.MacOSX | OperatingSystems.Windows, retryLimit) { }
/// <summary>
/// WARNING: This attribute should only be used on well understood flaky test failures caused by external issuesand should be removed once the underlying issues have been resolved.
/// This is not intended to be a long term solution to ensure passing of flaky tests but instead a method to improve test reliability without reducing coverage.
/// Issues should be filed to remove these attributes from affected tests as soon as the underlying issue is fixed.
/// </summary>
/// <param name="operatingSystems">The os(es) this retry should be attempted on.</param>
/// <param name="retryPredicateName">The predicate of the format Func&lt;Exception,bool&gt; that is used to determine if the test should be retried</param>
/// <param name="retryReason">The reason for retrying the test</param>
/// <param name="retryLimit">The number of retries to attempt before failing the test, for most purposes this this should be kept at 2 to avoid excessive retries.</param>
public RetryTestAttribute(string retryPredicateName, string retryReason, OperatingSystems operatingSystems, int retryLimit = 2)
{
if (string.IsNullOrEmpty(retryPredicateName))
{
throw new ArgumentNullException(nameof(RetryPredicateName), "A valid non-empty predicate method name must be provided.");
}
if (string.IsNullOrEmpty(retryReason))
{
throw new ArgumentNullException(nameof(retryReason), "A valid non-empty reason for retrying the test must be provided.");
}
if (retryLimit < 1)
{
throw new ArgumentOutOfRangeException(nameof(retryLimit), retryLimit, "Retry count must be positive.");
}
OperatingSystems = operatingSystems;
RetryPredicateName = retryPredicateName;
RetryReason = retryReason;
RetryLimit = retryLimit;
}
public string RetryPredicateName { get; }
public string RetryReason { get; }
public int RetryLimit { get; }
public OperatingSystems OperatingSystems { get; }
}
}

12
src/Logging/Logging.Testing/src/XunitLoggerFactoryExtensions.cs
View File

@ -22,6 +22,12 @@ namespace Microsoft.Extensions.Logging
return builder;
}
public static ILoggingBuilder AddXunit(this ILoggingBuilder builder, ITestOutputHelper output, LogLevel minLevel, DateTimeOffset? logStart)
{
builder.Services.AddSingleton<ILoggerProvider>(new XunitLoggerProvider(output, minLevel, logStart));
return builder;
}
public static ILoggerFactory AddXunit(this ILoggerFactory loggerFactory, ITestOutputHelper output)
{
loggerFactory.AddProvider(new XunitLoggerProvider(output));
@ -33,5 +39,11 @@ namespace Microsoft.Extensions.Logging
loggerFactory.AddProvider(new XunitLoggerProvider(output, minLevel));
return loggerFactory;
}
public static ILoggerFactory AddXunit(this ILoggerFactory loggerFactory, ITestOutputHelper output, LogLevel minLevel, DateTimeOffset? logStart)
{
loggerFactory.AddProvider(new XunitLoggerProvider(output, minLevel, logStart));
return loggerFactory;
}
}
}

16
src/Logging/Logging.Testing/src/XunitLoggerProvider.cs
View File

@ -12,6 +12,7 @@ namespace Microsoft.Extensions.Logging.Testing
{
private readonly ITestOutputHelper _output;
private readonly LogLevel _minLevel;
private readonly DateTimeOffset? _logStart;
public XunitLoggerProvider(ITestOutputHelper output)
: this(output, LogLevel.Trace)
@ -19,14 +20,20 @@ namespace Microsoft.Extensions.Logging.Testing
}
public XunitLoggerProvider(ITestOutputHelper output, LogLevel minLevel)
: this(output, minLevel, null)
{
}
public XunitLoggerProvider(ITestOutputHelper output, LogLevel minLevel, DateTimeOffset? logStart)
{
_output = output;
_minLevel = minLevel;
_logStart = logStart;
}
public ILogger CreateLogger(string categoryName)
{
return new XunitLogger(_output, categoryName, _minLevel);
return new XunitLogger(_output, categoryName, _minLevel, _logStart);
}
public void Dispose()
@ -40,12 +47,14 @@ namespace Microsoft.Extensions.Logging.Testing
private readonly string _category;
private readonly LogLevel _minLogLevel;
private readonly ITestOutputHelper _output;
private DateTimeOffset? _logStart;
public XunitLogger(ITestOutputHelper output, string category, LogLevel minLogLevel)
public XunitLogger(ITestOutputHelper output, string category, LogLevel minLogLevel, DateTimeOffset? logStart)
{
_minLogLevel = minLogLevel;
_category = category;
_output = output;
_logStart = logStart;
}
public void Log<TState>(
@ -59,7 +68,8 @@ namespace Microsoft.Extensions.Logging.Testing
// Buffer the message into a single string in order to avoid shearing the message when running across multiple threads.
var messageBuilder = new StringBuilder();
var timestamp = DateTime.Now.ToString("s");
var timestamp = _logStart.HasValue ? $"{(DateTimeOffset.UtcNow - _logStart.Value).TotalSeconds.ToString("N3")}s" : DateTimeOffset.UtcNow.ToString("s");
var firstLinePrefix = $"| [{timestamp}] {_category} {logLevel}: ";
var lines = formatter(state, exception).Split(NewLineChars, StringSplitOptions.RemoveEmptyEntries);
messageBuilder.AppendLine(firstLinePrefix + lines.FirstOrDefault() ?? string.Empty);

27
src/Logging/Logging.Testing/src/build/Microsoft.Extensions.Logging.Testing.props
View File

@ -1,8 +1,23 @@
<Project>
<ItemGroup>
<AssemblyAttribute Include="Xunit.TestFramework">
<_Parameter1>Microsoft.Extensions.Logging.Testing.LoggedTestFramework</_Parameter1>
<_Parameter2>Microsoft.Extensions.Logging.Testing</_Parameter2>
</AssemblyAttribute>
</ItemGroup>
<PropertyGroup>
<!-- Priority: LoggingTestingDisableFileLogging > LoggingTestingFileLoggingDirectory > ASPNETCORE_TEST_LOG_DIR > Default location -->
<LoggingTestingFileLoggingDirectory Condition="'$(LoggingTestingFileLoggingDirectory)' == ''">$(ASPNETCORE_TEST_LOG_DIR)</LoggingTestingFileLoggingDirectory>
<LoggingTestingFileLoggingDirectory Condition="'$(LoggingTestingFileLoggingDirectory)' == '' AND '$(RepositoryRoot)' != ''">$(RepositoryRoot)artifacts\logs\</LoggingTestingFileLoggingDirectory>
</PropertyGroup>
<Target Name="SetLoggingTestingAssemblyAttributes"
BeforeTargets="GetAssemblyAttributes"
Condition="'$(GenerateLoggingTestingAssemblyAttributes)' != 'false'">
<ItemGroup>
<AssemblyAttribute Include="Xunit.TestFramework">
<_Parameter1>Microsoft.Extensions.Logging.Testing.LoggedTestFramework</_Parameter1>
<_Parameter2>Microsoft.Extensions.Logging.Testing</_Parameter2>
</AssemblyAttribute>
<AssemblyAttribute Include="Microsoft.Extensions.Logging.Testing.TestFrameworkFileLoggerAttribute">
<_Parameter1>$(TargetFramework)</_Parameter1>
<_Parameter2 Condition="'$(LoggingTestingDisableFileLogging)' != 'true'">$(LoggingTestingFileLoggingDirectory)</_Parameter2>
</AssemblyAttribute>
</ItemGroup>
</Target>
</Project>

71
src/Logging/Logging.Testing/test/AssemblyTestLogTests.cs
View File

@ -6,7 +6,6 @@ using System.IO;
using System.Linq;
using System.Reflection;
using System.Runtime.CompilerServices;
using System.Runtime.InteropServices;
using System.Text.RegularExpressions;
using System.Threading.Tasks;
using Xunit;
@ -15,7 +14,9 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
{
public class AssemblyTestLogTests : LoggedTest
{
private static readonly Assembly ThisAssembly = typeof(AssemblyTestLog).GetTypeInfo().Assembly;
private static readonly Assembly ThisAssembly = typeof(AssemblyTestLogTests).GetTypeInfo().Assembly;
private static readonly string ThisAssemblyName = ThisAssembly.GetName().Name;
private static readonly string TFM = new DirectoryInfo(AppContext.BaseDirectory).Name;
[Fact]
public void FullClassNameUsedWhenShortClassNameAttributeNotSpecified()
@ -35,7 +36,7 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
public void TestLogWritesToITestOutputHelper()
{
var output = new TestTestOutputHelper();
var assemblyLog = AssemblyTestLog.Create("NonExistant.Test.Assembly", baseDirectory: null);
var assemblyLog = AssemblyTestLog.Create(ThisAssemblyName, baseDirectory: null);
using (assemblyLog.StartTestLog(output, "NonExistant.Test.Class", out var loggerFactory))
{
@ -46,20 +47,23 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
logger.LogTrace("Trace!");
}
Assert.Equal(@"[TIMESTAMP] TestLifetime Information: Starting test TestLogWritesToITestOutputHelper
[TIMESTAMP] TestLogger Information: Information!
[TIMESTAMP] TestLifetime Information: Finished test TestLogWritesToITestOutputHelper in DURATION
", MakeConsistent(output.Output), ignoreLineEndingDifferences: true);
var testLogContent = MakeConsistent(output.Output);
Assert.Equal(
@"[OFFSET] TestLifetime Information: Starting test TestLogWritesToITestOutputHelper at TIMESTAMP
[OFFSET] TestLogger Information: Information!
[OFFSET] TestLifetime Information: Finished test TestLogWritesToITestOutputHelper in DURATION
", testLogContent, ignoreLineEndingDifferences: true);
}
[Fact]
private Task TestLogEscapesIllegalFileNames() =>
RunTestLogFunctionalTest((tempDir) =>
{
var illegalTestName = "Testing-https://localhost:5000";
var escapedTestName = "Testing-https_localhost_5000";
using (var testAssemblyLog = AssemblyTestLog.Create("FakeTestAssembly", baseDirectory: tempDir))
using (testAssemblyLog.StartTestLog(output: null, className: "FakeTestAssembly.FakeTestClass", loggerFactory: out var testLoggerFactory, minLogLevel: LogLevel.Trace, resolvedTestName: out var resolvedTestname, testName: illegalTestName))
var illegalTestName = "T:e/s//t";
var escapedTestName = "T_e_s_t";
using (var testAssemblyLog = AssemblyTestLog.Create(ThisAssemblyName, baseDirectory: tempDir))
using (testAssemblyLog.StartTestLog(output: null, className: "FakeTestAssembly.FakeTestClass", loggerFactory: out var testLoggerFactory, minLogLevel: LogLevel.Trace, resolvedTestName: out var resolvedTestname, out var _, testName: illegalTestName))
{
Assert.Equal(escapedTestName, resolvedTestname);
}
@ -73,11 +77,11 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
// but it's also testing the test logging facility. So this is pretty meta ;)
var logger = LoggerFactory.CreateLogger("Test");
using (var testAssemblyLog = AssemblyTestLog.Create("FakeTestAssembly", tempDir))
using (var testAssemblyLog = AssemblyTestLog.Create(ThisAssemblyName, tempDir))
{
logger.LogInformation("Created test log in {baseDirectory}", tempDir);
using (testAssemblyLog.StartTestLog(output: null, className: "FakeTestAssembly.FakeTestClass", loggerFactory: out var testLoggerFactory, minLogLevel: LogLevel.Trace, testName: "FakeTestName"))
using (testAssemblyLog.StartTestLog(output: null, className: $"{ThisAssemblyName}.FakeTestClass", loggerFactory: out var testLoggerFactory, minLogLevel: LogLevel.Trace, testName: "FakeTestName"))
{
var testLogger = testLoggerFactory.CreateLogger("TestLogger");
testLogger.LogInformation("Information!");
@ -87,8 +91,8 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
logger.LogInformation("Finished test log in {baseDirectory}", tempDir);
var globalLogPath = Path.Combine(tempDir, "FakeTestAssembly", RuntimeInformation.FrameworkDescription.TrimStart('.'), "global.log");
var testLog = Path.Combine(tempDir, "FakeTestAssembly", RuntimeInformation.FrameworkDescription.TrimStart('.'), "FakeTestClass", $"FakeTestName.log");
var globalLogPath = Path.Combine(tempDir, ThisAssemblyName, TFM, "global.log");
var testLog = Path.Combine(tempDir, ThisAssemblyName, TFM, "FakeTestClass", "FakeTestName.log");
Assert.True(File.Exists(globalLogPath), $"Expected global log file {globalLogPath} to exist");
Assert.True(File.Exists(testLog), $"Expected test log file {testLog} to exist");
@ -96,14 +100,16 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
var globalLogContent = MakeConsistent(File.ReadAllText(globalLogPath));
var testLogContent = MakeConsistent(File.ReadAllText(testLog));
Assert.Equal(@"[GlobalTestLog] [Information] Global Test Logging initialized. Set the 'ASPNETCORE_TEST_LOG_DIR' Environment Variable in order to create log files on disk.
[GlobalTestLog] [Information] Starting test ""FakeTestName""
[GlobalTestLog] [Information] Finished test ""FakeTestName"" in DURATION
Assert.Equal(
@"[OFFSET] [GlobalTestLog] [Information] Global Test Logging initialized at TIMESTAMP. Configure the output directory via 'LoggingTestingFileLoggingDirectory' MSBuild property or set 'LoggingTestingDisableFileLogging' to 'true' to disable file logging.
[OFFSET] [GlobalTestLog] [Information] Starting test FakeTestName
[OFFSET] [GlobalTestLog] [Information] Finished test FakeTestName in DURATION
", globalLogContent, ignoreLineEndingDifferences: true);
Assert.Equal(@"[TestLifetime] [Information] Starting test ""FakeTestName""
[TestLogger] [Information] Information!
[TestLogger] [Verbose] Trace!
[TestLifetime] [Information] Finished test ""FakeTestName"" in DURATION
Assert.Equal(
@"[OFFSET] [TestLifetime] [Information] Starting test FakeTestName at TIMESTAMP
[OFFSET] [TestLogger] [Information] Information!
[OFFSET] [TestLogger] [Verbose] Trace!
[OFFSET] [TestLifetime] [Information] Finished test FakeTestName in DURATION
", testLogContent, ignoreLineEndingDifferences: true);
});
@ -113,18 +119,18 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
{
var longTestName = new string('0', 50) + new string('1', 50) + new string('2', 50) + new string('3', 50) + new string('4', 50);
var logger = LoggerFactory.CreateLogger("Test");
using (var testAssemblyLog = AssemblyTestLog.Create("FakeTestAssembly", tempDir))
using (var testAssemblyLog = AssemblyTestLog.Create(ThisAssemblyName, tempDir))
{
logger.LogInformation("Created test log in {baseDirectory}", tempDir);
using (testAssemblyLog.StartTestLog(output: null, className: "FakeTestAssembly.FakeTestClass", loggerFactory: out var testLoggerFactory, minLogLevel: LogLevel.Trace, testName: longTestName))
using (testAssemblyLog.StartTestLog(output: null, className: $"{ThisAssemblyName}.FakeTestClass", loggerFactory: out var testLoggerFactory, minLogLevel: LogLevel.Trace, testName: longTestName))
{
testLoggerFactory.CreateLogger("TestLogger").LogInformation("Information!");
}
}
logger.LogInformation("Finished test log in {baseDirectory}", tempDir);
var testLogFiles = new DirectoryInfo(Path.Combine(tempDir, "FakeTestAssembly", RuntimeInformation.FrameworkDescription.TrimStart('.'), "FakeTestClass")).EnumerateFiles();
var testLogFiles = new DirectoryInfo(Path.Combine(tempDir, ThisAssemblyName, TFM, "FakeTestClass")).EnumerateFiles();
var testLog = Assert.Single(testLogFiles);
var testFileName = Path.GetFileNameWithoutExtension(testLog.Name);
@ -139,13 +145,13 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
RunTestLogFunctionalTest((tempDir) =>
{
var logger = LoggerFactory.CreateLogger("Test");
using (var testAssemblyLog = AssemblyTestLog.Create("FakeTestAssembly", tempDir))
using (var testAssemblyLog = AssemblyTestLog.Create(ThisAssemblyName, tempDir))
{
logger.LogInformation("Created test log in {baseDirectory}", tempDir);
for (var i = 0; i < 10; i++)
{
using (testAssemblyLog.StartTestLog(output: null, className: "FakeTestAssembly.FakeTestClass", loggerFactory: out var testLoggerFactory, minLogLevel: LogLevel.Trace, testName: "FakeTestName"))
using (testAssemblyLog.StartTestLog(output: null, className: $"{ThisAssemblyName}.FakeTestClass", loggerFactory: out var testLoggerFactory, minLogLevel: LogLevel.Trace, testName: "FakeTestName"))
{
testLoggerFactory.CreateLogger("TestLogger").LogInformation("Information!");
}
@ -154,16 +160,17 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
logger.LogInformation("Finished test log in {baseDirectory}", tempDir);
// The first log file exists
Assert.True(File.Exists(Path.Combine(tempDir, "FakeTestAssembly", RuntimeInformation.FrameworkDescription.TrimStart('.'), "FakeTestClass", $"FakeTestName.log")));
Assert.True(File.Exists(Path.Combine(tempDir, ThisAssemblyName, TFM, "FakeTestClass", "FakeTestName.log")));
// Subsequent files exist
for (var i = 0; i < 9; i++)
{
Assert.True(File.Exists(Path.Combine(tempDir, "FakeTestAssembly", RuntimeInformation.FrameworkDescription.TrimStart('.'), "FakeTestClass", $"FakeTestName.{i}.log")));
Assert.True(File.Exists(Path.Combine(tempDir, ThisAssemblyName, TFM, "FakeTestClass", $"FakeTestName.{i}.log")));
}
});
private static readonly Regex TimestampRegex = new Regex(@"\d+-\d+-\d+T\d+:\d+:\d+");
private static readonly Regex TimestampOffsetRegex = new Regex(@"\d+\.\d+s");
private static readonly Regex DurationRegex = new Regex(@"[^ ]+s$");
private async Task RunTestLogFunctionalTest(Action<string> action, [CallerMemberName] string testName = null)
@ -197,10 +204,10 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
{
var strippedPrefix = line.IndexOf("[") >= 0 ? line.Substring(line.IndexOf("[")) : line;
var strippedDuration =
DurationRegex.Replace(strippedPrefix, "DURATION");
var strippedDuration = DurationRegex.Replace(strippedPrefix, "DURATION");
var strippedTimestamp = TimestampRegex.Replace(strippedDuration, "TIMESTAMP");
return strippedTimestamp;
var strippedTimestampOffset = TimestampOffsetRegex.Replace(strippedTimestamp, "OFFSET");
return strippedTimestampOffset;
}));
}
}

101
src/Logging/Logging.Testing/test/LoggedTestXunitRetryTests.cs Normal file
View File

@ -0,0 +1,101 @@
// 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;
using System.Linq;
using Microsoft.AspNetCore.Testing.xunit;
using Xunit;
namespace Microsoft.Extensions.Logging.Testing.Tests
{
[RetryTest(nameof(RetryAllPredicate), "sample reason")]
public class LoggedTestXunitRetryTests : LoggedTest
{
[Fact]
public void CompletesWithoutRetryOnSuccess()
{
Assert.Equal(2, RetryContext.Limit);
// This assert would fail on the second run
Assert.Equal(0, RetryContext.CurrentIteration);
}
[Fact]
public void RetriesUntilSuccess()
{
// This assert will fail the first time but pass on the second
Assert.Equal(1, RetryContext.CurrentIteration);
// This assert will ensure a message is logged for retried tests.
Assert.Equal(1, TestSink.Writes.Count);
var loggedMessage = TestSink.Writes.ToArray()[0];
Assert.Equal(LogLevel.Warning, loggedMessage.LogLevel);
Assert.Equal($"{nameof(RetriesUntilSuccess)} failed and retry conditions are met, re-executing. The reason for failure is sample reason.", loggedMessage.Message);
}
[ConditionalFact]
[OSSkipCondition(OperatingSystems.Windows)]
[RetryTest(nameof(RetryAllPredicate), "sample reason", OperatingSystems.Windows, 3)]
public void RetryCountNotOverridenWhenOSDoesNotMatch()
{
Assert.Equal(2, RetryContext.Limit);
}
[ConditionalFact]
[OSSkipCondition(OperatingSystems.Linux | OperatingSystems.MacOSX)]
[RetryTest(nameof(RetryAllPredicate), "sample reason", OperatingSystems.Windows, 3)]
public void RetryCountOverridenWhenOSMatches()
{
Assert.Equal(3, RetryContext.Limit);
}
[Fact]
[RetryTest(nameof(RetryInvalidOperationExceptionPredicate), "sample reason")]
public void RetryIfPredicateIsTrue()
{
if (RetryContext.CurrentIteration == 0)
{
Logger.LogWarning("Throw on first iteration");
throw new Exception();
}
// This assert will ensure a message is logged for retried tests.
Assert.Equal(1, TestSink.Writes.Count);
var loggedMessage = TestSink.Writes.ToArray()[0];
Assert.Equal(LogLevel.Warning, loggedMessage.LogLevel);
Assert.Equal($"{nameof(RetryIfPredicateIsTrue)} failed and retry conditions are met, re-executing. The reason for failure is sample reason.", loggedMessage.Message);
}
// Static predicates are valid
private static bool RetryAllPredicate(Exception e)
=> true;
// Instance predicates are valid
private bool RetryInvalidOperationExceptionPredicate(Exception e)
=> TestSink.Writes.Any(m => m.Message.Contains("Throw on first iteration"));
}
[RetryTest(nameof(RetryAllPredicate), "sample reason")]
public class LoggedTestXunitRetryConstructorTest : LoggedTest
{
private static int _constructorInvocationCount;
public LoggedTestXunitRetryConstructorTest()
{
_constructorInvocationCount++;
}
[Fact]
public void RetriesUntilSuccess()
{
// The constructor is invoked before the test method but the current iteration is updated after
Assert.Equal(_constructorInvocationCount, RetryContext.CurrentIteration + 1);
// This assert will fail the first time but pass on the second
Assert.Equal(1, RetryContext.CurrentIteration);
}
private static bool RetryAllPredicate(Exception e)
=> true;
}
}

20
src/Logging/Logging.Testing/test/LoggedTestXunitTests.cs
View File

@ -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.Reflection;
using Microsoft.AspNetCore.Testing.xunit;
using Microsoft.Extensions.DependencyInjection;
using Xunit;
@ -130,12 +131,29 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
}
}
public class LoggedTestXunitInitializationTests : TestLoggedTest
{
[Fact]
public void ITestOutputHelperInitializedByDefault()
{
Assert.True(ITestOutputHelperIsInitialized);
}
}
public class TestLoggedTest : LoggedTest
{
public bool SetupInvoked { get; private set; } = false;
public bool ITestOutputHelperIsInitialized { get; private set; } = false;
public override void AdditionalSetup()
public override void Initialize(MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper)
{
base.Initialize(methodInfo, testMethodArguments, testOutputHelper);
try
{
TestOutputHelper.WriteLine("Test");
ITestOutputHelperIsInitialized = true;
} catch { }
SetupInvoked = true;
}
}