Refactor xUnit extensibility

Adds our own hook for before/after logic that's more usable, called
`ITestMethodLifecycle`. This provides access to a context object
including the information about the test and the output helper. This can
be implemented by attributes or by the class itself.

The goal (and result) of this, is that we have a single *test executor*
extensibility point that provides all of the features we need. We should
use this everywhere we need features xUnit doesn't have.

Adding a new extensibility point (`ITestMethodLifecycle`) allows us to
do this without turning all of these features into a giant monolith.

---

Also updated our existing extensibility to use this new hook.

I did as much cleanup as a could to remove duplication from logging and
keep it loosly coupled. I didn't want to tease this apart completely
because the scope of this PR is already pretty large.
This commit is contained in:
Ryan Nowak 2019-09-16 13:33:09 -07:00
parent ce392fa4f7
commit 221985c254
9 changed files with 76 additions and 92 deletions

View File

@ -9,6 +9,7 @@ using System.Linq;
using System.Reflection;
using System.Runtime.CompilerServices;
using System.Text;
using Microsoft.AspNetCore.Testing;
using Microsoft.Extensions.DependencyInjection;
using Serilog;
using Serilog.Core;
@ -23,14 +24,6 @@ namespace Microsoft.Extensions.Logging.Testing
private static readonly string MaxPathLengthEnvironmentVariableName = "ASPNETCORE_TEST_LOG_MAXPATH";
private static readonly string LogFileExtension = ".log";
private static readonly int MaxPathLength = GetMaxPathLength();
private static char[] InvalidFileChars = new char[]
{
'\"', '<', '>', '|', '\0',
(char)1, (char)2, (char)3, (char)4, (char)5, (char)6, (char)7, (char)8, (char)9, (char)10,
(char)11, (char)12, (char)13, (char)14, (char)15, (char)16, (char)17, (char)18, (char)19, (char)20,
(char)21, (char)22, (char)23, (char)24, (char)25, (char)26, (char)27, (char)28, (char)29, (char)30,
(char)31, ':', '*', '?', '\\', '/', ' ', (char)127
};
private static readonly object _lock = new object();
private static readonly Dictionary<Assembly, AssemblyTestLog> _logs = new Dictionary<Assembly, AssemblyTestLog>();
@ -113,8 +106,8 @@ namespace Microsoft.Extensions.Logging.Testing
SerilogLoggerProvider serilogLoggerProvider = null;
if (!string.IsNullOrEmpty(_baseDirectory))
{
logOutputDirectory = Path.Combine(GetAssemblyBaseDirectory(_baseDirectory, _assembly), className);
testName = RemoveIllegalFileChars(testName);
logOutputDirectory = Path.Combine(_baseDirectory, className);
testName = TestFileOutputContext.RemoveIllegalFileChars(testName);
if (logOutputDirectory.Length + testName.Length + LogFileExtension.Length >= MaxPathLength)
{
@ -184,10 +177,10 @@ namespace Microsoft.Extensions.Logging.Testing
{
var logStart = DateTimeOffset.UtcNow;
SerilogLoggerProvider serilogLoggerProvider = null;
var globalLogDirectory = GetAssemblyBaseDirectory(baseDirectory, assembly);
if (!string.IsNullOrEmpty(globalLogDirectory))
if (!string.IsNullOrEmpty(baseDirectory))
{
var globalLogFileName = Path.Combine(globalLogDirectory, "global.log");
baseDirectory = TestFileOutputContext.GetAssemblyBaseDirectory(assembly, baseDirectory);
var globalLogFileName = Path.Combine(baseDirectory, "global.log");
serilogLoggerProvider = ConfigureFileLogging(globalLogFileName, logStart);
}
@ -222,31 +215,26 @@ namespace Microsoft.Extensions.Logging.Testing
{
if (!_logs.TryGetValue(assembly, out var log))
{
var baseDirectory = GetFileLoggerAttribute(assembly).BaseDirectory;
var baseDirectory = TestFileOutputContext.GetOutputDirectory(assembly);
log = Create(assembly, baseDirectory);
_logs[assembly] = log;
// Try to clear previous logs
var assemblyBaseDirectory = GetAssemblyBaseDirectory(baseDirectory, assembly);
if (Directory.Exists(assemblyBaseDirectory))
// Try to clear previous logs, continue if it fails.
var assemblyBaseDirectory = TestFileOutputContext.GetAssemblyBaseDirectory(assembly);
if (!string.IsNullOrEmpty(assemblyBaseDirectory))
{
try
{
Directory.Delete(assemblyBaseDirectory, recursive: true);
}
catch {}
catch { }
}
}
return log;
}
}
private static string GetAssemblyBaseDirectory(string baseDirectory, Assembly assembly)
=> string.IsNullOrEmpty(baseDirectory)
? string.Empty
: Path.Combine(baseDirectory, assembly.GetName().Name, GetFileLoggerAttribute(assembly).TFM);
private static TestFrameworkFileLoggerAttribute GetFileLoggerAttribute(Assembly assembly)
=> assembly.GetCustomAttribute<TestFrameworkFileLoggerAttribute>()
?? throw new InvalidOperationException($"No {nameof(TestFrameworkFileLoggerAttribute)} found on the assembly {assembly.GetName().Name}. "
@ -275,27 +263,6 @@ namespace Microsoft.Extensions.Logging.Testing
return new SerilogLoggerProvider(serilogger, dispose: true);
}
private static string RemoveIllegalFileChars(string s)
{
var sb = new StringBuilder();
foreach (var c in s)
{
if (InvalidFileChars.Contains(c))
{
if (sb.Length > 0 && sb[sb.Length - 1] != '_')
{
sb.Append('_');
}
}
else
{
sb.Append(c);
}
}
return sb.ToString();
}
public void Dispose()
{
(_serviceProvider as IDisposable)?.Dispose();

View File

@ -2,6 +2,11 @@
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using System;
using System.Diagnostics;
using System.IO;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Testing;
namespace Microsoft.Extensions.Logging.Testing
{
@ -12,7 +17,23 @@ namespace Microsoft.Extensions.Logging.Testing
/// This currently only works in Windows environments
/// </remarks>
[AttributeUsage(AttributeTargets.Method, AllowMultiple = false)]
public class CollectDumpAttribute : Attribute
public class CollectDumpAttribute : Attribute, ITestMethodLifecycle
{
public Task OnTestStartAsync(TestContext context, CancellationToken cancellationToken)
{
return Task.CompletedTask;
}
public Task OnTestEndAsync(TestContext context, Exception exception, CancellationToken cancellationToken)
{
if (exception != null)
{
var path = Path.Combine(context.FileOutput.TestClassOutputDirectory, context.FileOutput.GetUniqueFileName(context.FileOutput.TestName, ".dmp"));
var process = Process.GetCurrentProcess();
DumpCollector.Collect(process, path);
}
return Task.CompletedTask;
}
}
}

View File

@ -3,6 +3,7 @@
using System;
using System.Reflection;
using Microsoft.AspNetCore.Testing;
using Xunit.Abstractions;
namespace Microsoft.Extensions.Logging.Testing
@ -18,6 +19,6 @@ namespace Microsoft.Extensions.Logging.Testing
// For back compat
IDisposable StartLog(out ILoggerFactory loggerFactory, LogLevel minLogLevel, string testName);
void Initialize(MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper);
void Initialize(TestContext context, MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper);
}
}

View File

@ -2,6 +2,7 @@
// 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;
using Xunit.Abstractions;
namespace Microsoft.Extensions.Logging.Testing
@ -13,9 +14,9 @@ namespace Microsoft.Extensions.Logging.Testing
public ITestSink TestSink { get; set; }
public override void Initialize(MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper)
public override void Initialize(TestContext context, MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper)
{
base.Initialize(methodInfo, testMethodArguments, testOutputHelper);
base.Initialize(context, methodInfo, testMethodArguments, testOutputHelper);
TestSink = new TestSink();
LoggerFactory.AddProvider(new TestLoggerProvider(TestSink));

View File

@ -6,12 +6,16 @@ using System.Linq;
using System.Reflection;
using System.Runtime.CompilerServices;
using System.Runtime.ExceptionServices;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Testing;
using Microsoft.Extensions.DependencyInjection;
using Serilog;
using Xunit.Abstractions;
namespace Microsoft.Extensions.Logging.Testing
{
public class LoggedTestBase : ILoggedTest
public class LoggedTestBase : ILoggedTest, ITestMethodLifecycle
{
private ExceptionDispatchInfo _initializationException;
@ -23,11 +27,11 @@ namespace Microsoft.Extensions.Logging.Testing
TestOutputHelper = output;
}
protected TestContext Context { get; private set; }
// Internal for testing
internal string ResolvedTestClassName { get; set; }
internal RepeatContext RepeatContext { get; set; }
public string ResolvedLogOutputDirectory { get; set; }
public string ResolvedTestMethodName { get; set; }
@ -49,7 +53,7 @@ namespace Microsoft.Extensions.Logging.Testing
return AssemblyTestLog.ForAssembly(GetType().GetTypeInfo().Assembly).StartTestLog(TestOutputHelper, GetType().FullName, out loggerFactory, minLogLevel, testName);
}
public virtual void Initialize(MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper)
public virtual void Initialize(TestContext context, MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper)
{
try
{
@ -59,25 +63,22 @@ namespace Microsoft.Extensions.Logging.Testing
var logLevelAttribute = methodInfo.GetCustomAttribute<LogLevelAttribute>()
?? methodInfo.DeclaringType.GetCustomAttribute<LogLevelAttribute>()
?? methodInfo.DeclaringType.Assembly.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;
ResolvedTestClassName = context.FileOutput.TestClassName;
_testLog = AssemblyTestLog
.ForAssembly(classType.GetTypeInfo().Assembly)
.StartTestLog(
TestOutputHelper,
ResolvedTestClassName,
context.FileOutput.TestClassName,
out var loggerFactory,
logLevelAttribute?.LogLevel ?? LogLevel.Debug,
out var resolvedTestName,
out var logOutputDirectory,
testName);
out var logDirectory,
context.FileOutput.TestName);
ResolvedLogOutputDirectory = logOutputDirectory;
ResolvedLogOutputDirectory = logDirectory;
ResolvedTestMethodName = resolvedTestName;
LoggerFactory = loggerFactory;
@ -91,7 +92,7 @@ namespace Microsoft.Extensions.Logging.Testing
public virtual void Dispose()
{
if(_testLog == null)
if (_testLog == null)
{
// It seems like sometimes the MSBuild goop that adds the test framework can end up in a bad state and not actually add it
// Not sure yet why that happens but the exception isn't clear so I'm adding this error so we can detect it better.
@ -102,5 +103,19 @@ namespace Microsoft.Extensions.Logging.Testing
_initializationException?.Throw();
_testLog.Dispose();
}
Task ITestMethodLifecycle.OnTestStartAsync(TestContext context, CancellationToken cancellationToken)
{
Context = context;
Initialize(context, context.TestMethod, context.MethodArguments, context.Output);
return Task.CompletedTask;
}
Task ITestMethodLifecycle.OnTestEndAsync(TestContext context, Exception exception, CancellationToken cancellationToken)
{
return Task.CompletedTask;
}
}
}

View File

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

View File

@ -11,8 +11,8 @@
Condition="'$(GenerateLoggingTestingAssemblyAttributes)' != 'false'">
<ItemGroup>
<AssemblyAttribute Include="Xunit.TestFramework">
<_Parameter1>Microsoft.Extensions.Logging.Testing.LoggedTestFramework</_Parameter1>
<_Parameter2>Microsoft.Extensions.Logging.Testing</_Parameter2>
<_Parameter1>Microsoft.AspNetCore.Testing.AspNetTestFramework</_Parameter1>
<_Parameter2>Microsoft.AspNetCore.Testing</_Parameter2>
</AssemblyAttribute>
<AssemblyAttribute Include="Microsoft.Extensions.Logging.Testing.TestFrameworkFileLoggerAttribute">

View File

@ -18,12 +18,6 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
private static readonly string ThisAssemblyName = ThisAssembly.GetName().Name;
private static readonly string TFM = new DirectoryInfo(AppContext.BaseDirectory).Name;
[Fact]
public void FullClassNameUsedWhenShortClassNameAttributeNotSpecified()
{
Assert.Equal(GetType().FullName, ResolvedTestClassName);
}
[Fact]
public void ForAssembly_ReturnsSameInstanceForSameAssembly()
{
@ -57,7 +51,7 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
}
[Fact]
private Task TestLogEscapesIllegalFileNames() =>
public Task TestLogEscapesIllegalFileNames() =>
RunTestLogFunctionalTest((tempDir) =>
{
var illegalTestName = "T:e/s//t";

View File

@ -21,18 +21,6 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
_output = output;
}
[Fact]
public void ShortClassNameUsedWhenShortClassNameAttributeSpecified()
{
Assert.Equal(GetType().Name, ResolvedTestClassName);
}
[Fact]
public void LoggedTestTestOutputHelperSameInstanceAsInjectedConstructorArg()
{
Assert.Same(_output, TestOutputHelper);
}
[Fact]
public void LoggedFactInitializesLoggedTestProperties()
{
@ -189,9 +177,9 @@ namespace Microsoft.Extensions.Logging.Testing.Tests
public bool SetupInvoked { get; private set; } = false;
public bool ITestOutputHelperIsInitialized { get; private set; } = false;
public override void Initialize(MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper)
public override void Initialize(TestContext context, MethodInfo methodInfo, object[] testMethodArguments, ITestOutputHelper testOutputHelper)
{
base.Initialize(methodInfo, testMethodArguments, testOutputHelper);
base.Initialize(context, methodInfo, testMethodArguments, testOutputHelper);
try
{