diff --git a/src/Microsoft.TestPlatform.Common/ExtensionFramework/TestPluginCache.cs b/src/Microsoft.TestPlatform.Common/ExtensionFramework/TestPluginCache.cs index b7301292e3..7d47063c05 100644 --- a/src/Microsoft.TestPlatform.Common/ExtensionFramework/TestPluginCache.cs +++ b/src/Microsoft.TestPlatform.Common/ExtensionFramework/TestPluginCache.cs @@ -264,6 +264,11 @@ public void ClearExtensions() _filterableExtensionPaths?.Clear(); _unfilterableExtensionPaths?.Clear(); TestExtensions?.InvalidateCache(); + + // Extensions are discovered from scratch after this, so a load failure the user was already told + // about is news again. Without this the runner reports a broken extension on the first request and + // then stays quiet about it for the rest of a design mode session that can last hours. + TestPluginDiscoverer.ClearReportedFiles(); } /// diff --git a/src/Microsoft.TestPlatform.Common/ExtensionFramework/TestPluginDiscoverer.cs b/src/Microsoft.TestPlatform.Common/ExtensionFramework/TestPluginDiscoverer.cs index 5c0cdf8354..3931bad37d 100644 --- a/src/Microsoft.TestPlatform.Common/ExtensionFramework/TestPluginDiscoverer.cs +++ b/src/Microsoft.TestPlatform.Common/ExtensionFramework/TestPluginDiscoverer.cs @@ -2,6 +2,7 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. using System; +using System.Collections.Concurrent; using System.Collections.Generic; using System.Globalization; using System.IO; @@ -25,6 +26,30 @@ internal static class TestPluginDiscoverer { private static readonly HashSet UnloadableFiles = new(); + /// + /// Files we already told the user about, so that a file that fails for every extension type is + /// reported once per run instead of once per scan. + /// empties it, which is what makes this once per run rather than once per process: the runner clears + /// the extension cache before every discovery or run request, so an editor that keeps the runner alive + /// for hours still hears about a broken extension on each request, and the set cannot grow past the + /// files of a single request. + /// + /// Paths are compared ignoring case. On Windows two spellings of the same path are the same file and + /// warning about both would be a duplicate the user cannot act on. Elsewhere they can be two files, + /// but the only cost of merging them is one warning less about a file that is broken anyway. + /// + private static readonly ConcurrentDictionary ReportedFiles = new(StringComparer.OrdinalIgnoreCase); + + /// + /// Extensions that are probed speculatively when no other extension was found, see . + /// They are absent in every environment except UWP, so failing to load them is expected and is not reported. + /// + private static readonly string[] KnownExtensions = + { + "Microsoft.VisualStudio.TestTools.CppUnitTestFramework.CppUnitTestExtension.dll", + "Microsoft.VisualStudio.TestPlatform.Extensions.MSAppContainerAdapter.dll", + }; + /// /// Gets information about each of the test extensions available. /// @@ -56,9 +81,44 @@ private static void AddKnownExtensions(ref IEnumerable extensionPaths) // For C++ UWP adapter, & OLD C# UWP(MSTest V1) adapter // In UWP .Net Native Compilation mode managed dll's are packaged differently, & File.Exists() fails. // Include these two dll's if so far no adapters(extensions) were found, & let Assembly.Load() fail if they are not present. - extensionPaths = extensionPaths.Concat(new[] { "Microsoft.VisualStudio.TestTools.CppUnitTestFramework.CppUnitTestExtension.dll", "Microsoft.VisualStudio.TestPlatform.Extensions.MSAppContainerAdapter.dll" }); + extensionPaths = extensionPaths.Concat(KnownExtensions); } + /// + /// Tells the user that an extension file did not load. Extension scanning is best effort, so this is a + /// warning and never stops the run, but staying silent leaves the user with fewer extensions than they + /// expect and no way to find out why short of re-running with /diag. + /// + /// The file that failed to load. + private static void ReportExtensionLoadFailure(string file) + { + // Many files are scanned per run, and the same file is scanned once per extension type, so report it once. + if (!ReportedFiles.TryAdd(file, 0)) + { + return; + } + + // This runs inside a catch block. Reporting a load failure must never turn into a second failure that + // escapes and takes down a run that would otherwise have finished, so swallow anything that goes wrong + // here, for instance a satellite assembly that cannot be resolved while formatting the message. + try + { + string message = string.Format(CultureInfo.CurrentCulture, CommonResources.FailedToLoadAdapaterFile, file); + TestSessionMessageLogger.Instance.SendMessage(TestMessageLevel.Warning, message); + } + catch (Exception e) + { + EqtTrace.Warning("TestPluginDiscoverer: Failed to report the load failure of file '{0}'. Error: {1}", file, e); + } + } + + /// + /// Forgets which files were already reported, so the next request reports them again. Called when the + /// extension cache is cleared, because extensions are then discovered from scratch and a failure the + /// user was told about before the clear is news again. + /// + internal static void ClearReportedFiles() => ReportedFiles.Clear(); + /// /// Gets test extension information from the given collection of files. /// @@ -101,13 +161,25 @@ private static void GetTestExtensionsFromFiles( catch (FileLoadException e) { EqtTrace.Warning("TestPluginDiscoverer-FileLoadException: Failed to load extensions from file '{0}'. Skipping test extension scan for this file. Error: {1}", file, e); - string fileLoadErrorMessage = string.Format(CultureInfo.CurrentCulture, CommonResources.FailedToLoadAdapaterFile, file); - TestSessionMessageLogger.Instance.SendMessage(TestMessageLevel.Warning, fileLoadErrorMessage); + ReportExtensionLoadFailure(file); UnloadableFiles.Add(file); } catch (Exception e) { EqtTrace.Warning("TestPluginDiscoverer: Failed to load extensions from file '{0}'. Skipping test extension scan for this file. Error: {1}", file, e); + + // This is the handler that catches FileNotFoundException, which is what Assembly.Load throws when + // the extension, or one of its dependencies, cannot be found. That is a real problem for the user, + // so report it instead of only tracing it. The file is deliberately not added to UnloadableFiles: + // unlike FileLoadException this also catches failures from scanning an assembly that did load, and + // resolution can succeed on a later pass once more extension directories are registered. + // + // The speculatively probed extensions are the exception, they are expected to be missing everywhere + // except UWP and reporting them would warn on every run. + if (!KnownExtensions.Contains(file, StringComparer.OrdinalIgnoreCase)) + { + ReportExtensionLoadFailure(file); + } } } } @@ -124,7 +196,7 @@ private static void GetTestExtensionsFromFiles( /// /// Type of Extensions. /// - private static void GetTestExtensionsFromAssembly(Assembly assembly, Dictionary pluginInfos, string filePath) + internal static void GetTestExtensionsFromAssembly(Assembly assembly, Dictionary pluginInfos, string filePath) where TPluginInfo : TestPluginInformation { TPDebug.Assert(assembly != null, "null assembly"); @@ -163,6 +235,12 @@ private static void GetTestExtensionsFromAssembly(Assem { EqtTrace.Warning("TestPluginDiscoverer: Failed to get types from assembly '{0}'. Error: {1}", assembly.FullName, e.ToString()); + // The assembly itself loaded, but some of its types did not, usually because a dependency is + // missing. Scanning continues with the types that did load, so without this the user silently + // gets fewer extensions than the assembly declares. The file is deliberately not added to + // UnloadableFiles, the types that did load are still worth scanning on the next pass. + ReportExtensionLoadFailure(filePath); + if (e.Types?.Length > 0) { // Unloaded types on e.Types are null, make sure we skip them. diff --git a/test/Microsoft.TestPlatform.Common.UnitTests/ExtensionFramework/TestPluginDiscovererTests.cs b/test/Microsoft.TestPlatform.Common.UnitTests/ExtensionFramework/TestPluginDiscovererTests.cs index ec7e42b5d5..f41d8b4e2d 100644 --- a/test/Microsoft.TestPlatform.Common.UnitTests/ExtensionFramework/TestPluginDiscovererTests.cs +++ b/test/Microsoft.TestPlatform.Common.UnitTests/ExtensionFramework/TestPluginDiscovererTests.cs @@ -3,14 +3,18 @@ using System; using System.Collections.Generic; +using System.IO; using System.Linq; +using System.Reflection; using System.Threading; using System.Threading.Tasks; using System.Xml; +using Microsoft.TestPlatform.TestUtilities; using Microsoft.VisualStudio.TestPlatform.Common.DataCollector; using Microsoft.VisualStudio.TestPlatform.Common.ExtensionFramework; using Microsoft.VisualStudio.TestPlatform.Common.ExtensionFramework.Utilities; +using Microsoft.VisualStudio.TestPlatform.Common.Logging; using Microsoft.VisualStudio.TestPlatform.ObjectModel; using Microsoft.VisualStudio.TestPlatform.ObjectModel.Adapter; using Microsoft.VisualStudio.TestPlatform.ObjectModel.Client; @@ -23,6 +27,38 @@ namespace TestPlatform.Common.UnitTests.ExtensionFramework; [TestClass] public class TestPluginDiscovererTests { + private readonly List _messages = new(); + + [TestInitialize] + public void Initialize() + { + TestSessionMessageLogger.Instance.TestRunMessage += OnTestRunMessage; + } + + [TestCleanup] + public void Cleanup() + { + // The logger is a process wide singleton, so drop the whole instance to make sure the handler + // above does not observe messages from the tests that run after this one. + TestSessionMessageLogger.Instance.TestRunMessage -= OnTestRunMessage; + TestSessionMessageLogger.Instance = null; + + // So does the plugin cache, and one of the tests below clears it. + TestPluginCacheHelper.ResetExtensionsCache(); + } + + private void OnTestRunMessage(object? sender, TestRunMessageEventArgs e) => _messages.Add(e); + + /// + /// TestPluginDiscoverer remembers the files it failed on until the extension cache is cleared, so every + /// test that wants to observe a failure needs a file name no other test has used. + /// + private static string GetPathOfMissingExtension() + => Path.Combine(Path.GetTempPath(), $"missing{Guid.NewGuid():N}.TestAdapter.dll"); + + private IEnumerable MessagesAbout(string file) + => _messages.Where(m => m.Message.IndexOf(file, StringComparison.OrdinalIgnoreCase) >= 0); + [TestMethod] public void GetTestExtensionsInformationShouldNotThrowOnALoadException() { @@ -133,8 +169,140 @@ public void GetTestExtensionsInformationShouldNotAbortOnFaultyExtensions() _ = TestPluginDiscoverer.GetTestExtensionsInformation(pathToExtensions); } + [TestMethod] + public void GetTestExtensionsInformationShouldWarnWhenAFileCannotBeLoaded() + { + var missingExtension = GetPathOfMissingExtension(); + + _ = TestPluginDiscoverer.GetTestExtensionsInformation(new List { missingExtension }); + + var warning = _messages.SingleOrDefault(m => m.Level == TestMessageLevel.Warning && m.Message.Contains(missingExtension)); + Assert.IsNotNull(warning, $"Expected a warning naming '{missingExtension}', got: {string.Join(", ", _messages.Select(m => m.Message))}"); + } + + [TestMethod] + public void GetTestExtensionsInformationShouldWarnAboutTheSameFileOnlyOnce() + { + var missingExtension = GetPathOfMissingExtension(); + var pathToExtensions = new List { missingExtension }; + + // The same file is scanned once per extension type, the user should hear about it once. + _ = TestPluginDiscoverer.GetTestExtensionsInformation(pathToExtensions); + _ = TestPluginDiscoverer.GetTestExtensionsInformation(pathToExtensions); + + Assert.ContainsSingle(_messages.Where(m => m.Message.Contains(missingExtension))); + } + + [TestMethod] + public void GetTestExtensionsInformationShouldWarnAboutTheSameFileOnlyOnceWhenTheCasingDiffers() + { + var missingExtension = GetPathOfMissingExtension(); + + _ = TestPluginDiscoverer.GetTestExtensionsInformation( + new List { missingExtension }); + _ = TestPluginDiscoverer.GetTestExtensionsInformation( + new List { missingExtension.ToUpperInvariant() }); + + // On Windows those two paths are the same file, and a second warning about it tells the user nothing + // they cannot already see in the first. + Assert.ContainsSingle(MessagesAbout(missingExtension)); + } + + [TestMethod] + public void GetTestExtensionsInformationShouldWarnAgainAfterTheExtensionCacheIsCleared() + { + var missingExtension = GetPathOfMissingExtension(); + var pathToExtensions = new List { missingExtension }; + + _ = TestPluginDiscoverer.GetTestExtensionsInformation(pathToExtensions); + + // This is what the runner does before every discovery or run request. Reporting once per run has to + // mean once per run even in an editor that keeps the runner alive across many of them, otherwise the + // user is told about a broken extension once and never again. + TestPluginCache.Instance.ClearExtensions(); + + _ = TestPluginDiscoverer.GetTestExtensionsInformation(pathToExtensions); + + Assert.HasCount(2, MessagesAbout(missingExtension).ToList()); + } + + [TestMethod] + public void GetTestExtensionsInformationShouldNotWarnAboutSpeculativelyProbedExtensions() + { + // With no extension paths the discoverer probes for the two C++ UWP adapters, which are missing + // everywhere except UWP. Warning about those would put two warnings on every run. + _ = TestPluginDiscoverer.GetTestExtensionsInformation(new List()); + + Assert.IsEmpty(_messages); + } + + [TestMethod] + public void GetTestExtensionsFromAssemblyShouldWarnAndKeepTheTypesThatLoadedOnReflectionTypeLoadException() + { + var filePath = GetPathOfMissingExtension(); + var assembly = new PartiallyLoadedAssembly(typeof(ValidDiscoverer), null); + var pluginInfos = new Dictionary(); + + TestPluginDiscoverer.GetTestExtensionsFromAssembly(assembly, pluginInfos, filePath); + + // The types that did load are still discovered, half an adapter is better than none. + var expected = new TestDiscovererPluginInformation(typeof(ValidDiscoverer)); + Assert.IsTrue(pluginInfos.ContainsKey(expected.IdentifierData!)); + + // And the user is told, instead of only finding out by re-running with /diag. + var warning = _messages.SingleOrDefault(m => m.Level == TestMessageLevel.Warning && m.Message.Contains(filePath)); + Assert.IsNotNull(warning, $"Expected a warning naming '{filePath}', got: {string.Join(", ", _messages.Select(m => m.Message))}"); + } + + [TestMethod] + public void GetTestExtensionsFromAssemblyShouldWarnOnceButKeepScanningTheAssembly() + { + var filePath = GetPathOfMissingExtension(); + var assembly = new PartiallyLoadedAssembly(typeof(ValidDiscoverer), null); + var firstScan = new Dictionary(); + var secondScan = new Dictionary(); + + TestPluginDiscoverer.GetTestExtensionsFromAssembly(assembly, firstScan, filePath); + TestPluginDiscoverer.GetTestExtensionsFromAssembly(assembly, secondScan, filePath); + + Assert.ContainsSingle(_messages.Where(m => m.Message.Contains(filePath))); + + // Reporting once must not mean scanning once, the partially loaded assembly still has to be scanned + // for every extension type. + var expected = new TestDiscovererPluginInformation(typeof(ValidDiscoverer)); + Assert.IsTrue(secondScan.ContainsKey(expected.IdentifierData!)); + } + #region Implementations + /// + /// An assembly that loaded but whose types did not, the way a real adapter behaves when one of its + /// dependencies is missing. holds null for every type + /// that failed, which is what makes discovery silently return fewer extensions than the file declares. + /// + private sealed class PartiallyLoadedAssembly : Assembly + { + private readonly Type?[] _loadedTypes; + + public PartiallyLoadedAssembly(params Type?[] loadedTypes) => _loadedTypes = loadedTypes; + + public override string FullName => "PartiallyLoadedAssembly, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null"; + + public override Type[] GetTypes() + => throw new ReflectionTypeLoadException( + _loadedTypes, + new Exception[] { new FileNotFoundException("Could not load file or assembly 'Microsoft.Bcl.AsyncInterfaces, Version=9.0.0.8, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51'. The system cannot find the file specified.") }); + + public override Type? GetType(string name, bool throwOnError, bool ignoreCase) => null; + + // These have to hand back an Attribute[], the reflection helpers cast the result back to one. + public override object[] GetCustomAttributes(bool inherit) => Array.Empty(); + + public override object[] GetCustomAttributes(Type attributeType, bool inherit) => Array.Empty(); + + public override bool IsDefined(Type attributeType, bool inherit) => false; + } + #region Discoverers private abstract class AbstractTestDiscoverer : ITestDiscoverer