From 221985c254773e10da453c4d4b1381677b275a71 Mon Sep 17 00:00:00 2001 From: Ryan Nowak Date: Mon, 16 Sep 2019 13:33:09 -0700 Subject: [PATCH] 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. --- src/Testing/src/AssemblyTestLog.cs | 55 ++++--------------- src/Testing/src/CollectDumpAttribute.cs | 23 +++++++- src/Testing/src/LoggedTest/ILoggedTest.cs | 3 +- src/Testing/src/LoggedTest/LoggedTest.cs | 5 +- src/Testing/src/LoggedTest/LoggedTestBase.cs | 41 +++++++++----- .../src/TestFrameworkFileLoggerAttribute.cs | 13 ++--- ...Microsoft.Extensions.Logging.Testing.props | 4 +- src/Testing/test/AssemblyTestLogTests.cs | 8 +-- src/Testing/test/LoggedTestXunitTests.cs | 16 +----- 9 files changed, 76 insertions(+), 92 deletions(-) diff --git a/src/Testing/src/AssemblyTestLog.cs b/src/Testing/src/AssemblyTestLog.cs index e84df52554..3c598b67d5 100644 --- a/src/Testing/src/AssemblyTestLog.cs +++ b/src/Testing/src/AssemblyTestLog.cs @@ -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 _logs = new Dictionary(); @@ -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() ?? 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(); diff --git a/src/Testing/src/CollectDumpAttribute.cs b/src/Testing/src/CollectDumpAttribute.cs index 8a6aa84bac..012a5c8fa1 100644 --- a/src/Testing/src/CollectDumpAttribute.cs +++ b/src/Testing/src/CollectDumpAttribute.cs @@ -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 /// [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; + } } } diff --git a/src/Testing/src/LoggedTest/ILoggedTest.cs b/src/Testing/src/LoggedTest/ILoggedTest.cs index a563cbdaf9..a906ae84a2 100644 --- a/src/Testing/src/LoggedTest/ILoggedTest.cs +++ b/src/Testing/src/LoggedTest/ILoggedTest.cs @@ -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); } } diff --git a/src/Testing/src/LoggedTest/LoggedTest.cs b/src/Testing/src/LoggedTest/LoggedTest.cs index 64a9adec06..d108ffb7e8 100644 --- a/src/Testing/src/LoggedTest/LoggedTest.cs +++ b/src/Testing/src/LoggedTest/LoggedTest.cs @@ -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)); diff --git a/src/Testing/src/LoggedTest/LoggedTestBase.cs b/src/Testing/src/LoggedTest/LoggedTestBase.cs index 94cdf82257..324b855319 100644 --- a/src/Testing/src/LoggedTest/LoggedTestBase.cs +++ b/src/Testing/src/LoggedTest/LoggedTestBase.cs @@ -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() ?? methodInfo.DeclaringType.GetCustomAttribute() ?? methodInfo.DeclaringType.Assembly.GetCustomAttribute(); - var testName = testMethodArguments.Aggregate(methodInfo.Name, (a, b) => $"{a}-{(b ?? "null")}"); - var useShortClassName = methodInfo.DeclaringType.GetCustomAttribute() - ?? methodInfo.DeclaringType.Assembly.GetCustomAttribute(); // 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; + } } } diff --git a/src/Testing/src/TestFrameworkFileLoggerAttribute.cs b/src/Testing/src/TestFrameworkFileLoggerAttribute.cs index 32d8f30584..025a5a9bd8 100644 --- a/src/Testing/src/TestFrameworkFileLoggerAttribute.cs +++ b/src/Testing/src/TestFrameworkFileLoggerAttribute.cs @@ -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; } } -} \ No newline at end of file +} diff --git a/src/Testing/src/build/Microsoft.Extensions.Logging.Testing.props b/src/Testing/src/build/Microsoft.Extensions.Logging.Testing.props index c503c32d40..3895cb5471 100644 --- a/src/Testing/src/build/Microsoft.Extensions.Logging.Testing.props +++ b/src/Testing/src/build/Microsoft.Extensions.Logging.Testing.props @@ -11,8 +11,8 @@ Condition="'$(GenerateLoggingTestingAssemblyAttributes)' != 'false'"> - <_Parameter1>Microsoft.Extensions.Logging.Testing.LoggedTestFramework - <_Parameter2>Microsoft.Extensions.Logging.Testing + <_Parameter1>Microsoft.AspNetCore.Testing.AspNetTestFramework + <_Parameter2>Microsoft.AspNetCore.Testing diff --git a/src/Testing/test/AssemblyTestLogTests.cs b/src/Testing/test/AssemblyTestLogTests.cs index 20f597defc..6d7ae5139a 100644 --- a/src/Testing/test/AssemblyTestLogTests.cs +++ b/src/Testing/test/AssemblyTestLogTests.cs @@ -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"; diff --git a/src/Testing/test/LoggedTestXunitTests.cs b/src/Testing/test/LoggedTestXunitTests.cs index ab9ee746c3..d8454023a2 100644 --- a/src/Testing/test/LoggedTestXunitTests.cs +++ b/src/Testing/test/LoggedTestXunitTests.cs @@ -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 {