Use Xunit's ITestOutputHelper throughout. Other minor tidy-ups.

test/Templates.Test/EmptyWebTemplateTest.cs

@@ -1,9 +1,14 @@
 using Xunit;
+using Xunit.Abstractions;
 
 namespace Templates.Test
 {
     public class EmptyWebTemplateTest : TemplateTestBase
     {
+        public EmptyWebTemplateTest(ITestOutputHelper output) : base(output)
+        {
+        }
+
         [Theory]
         [InlineData(null)]
         [InlineData("net461")]

test/Templates.Test/Helpers/AspNetProcess.cs

@@ -6,6 +6,7 @@ using System.Linq;
 using System.Net;
 using System.Net.Http;
 using Xunit;
+using Xunit.Abstractions;
 
 namespace Templates.Test.Helpers
 {
@@ -17,23 +18,27 @@ namespace Templates.Test.Helpers
         private readonly ProcessEx _process;
         private readonly Uri _listeningUri;
         private readonly HttpClient _httpClient;
+        private readonly ITestOutputHelper _output;
 
-        public AspNetProcess(string workingDirectory, string projectName, string targetFrameworkOverride, bool publish)
+        public AspNetProcess(ITestOutputHelper output, string workingDirectory, string projectName, string targetFrameworkOverride, bool publish)
         {
+            _output = output;
             _httpClient = new HttpClient();
 
             var framework = string.IsNullOrEmpty(targetFrameworkOverride) ? DefaultFramework : targetFrameworkOverride;
             if (publish)
             {
+                output.WriteLine("Publishing ASP.NET application...");
                 ProcessEx
-                    .Run(workingDirectory, "dotnet", "publish -c Release")
+                    .Run(output, workingDirectory, "dotnet", "publish -c Release")
                     .WaitForExit(assertSuccess: true);
                 workingDirectory = Path.Combine(workingDirectory, "bin", "Release", framework, "publish");
             }
             else
             {
+                output.WriteLine("Building ASP.NET application...");
                 ProcessEx
-                    .Run(workingDirectory, "dotnet", "build --no-restore -c Debug")
+                    .Run(output, workingDirectory, "dotnet", "build --no-restore -c Debug")
                     .WaitForExit(assertSuccess: true);
             }
 
@@ -47,20 +52,22 @@ namespace Templates.Test.Helpers
                 envVars["ASPNETCORE_ENVIRONMENT"] = "Development";
             }
 
+            output.WriteLine("Running ASP.NET application...");
             if (framework.StartsWith("netcore"))
             {
                 var dllPath = publish ? $"{projectName}.dll" : $"bin/Debug/{framework}/{projectName}.dll";
-                _process = ProcessEx.Run(workingDirectory, "dotnet", $"exec {dllPath}", envVars: envVars);
+                _process = ProcessEx.Run(output, workingDirectory, "dotnet", $"exec {dllPath}", envVars: envVars);
             }
             else
             {
                 var exeFullPath = publish
                     ? Path.Combine(workingDirectory, $"{projectName}.exe")
                     : Path.Combine(workingDirectory, "bin", "Debug", framework, $"{projectName}.exe");
-                _process = ProcessEx.Run(workingDirectory, exeFullPath, envVars: envVars);
+                _process = ProcessEx.Run(output, workingDirectory, exeFullPath, envVars: envVars);
             }
-            
+
             // Wait until the app is accepting HTTP requests
+            output.WriteLine("Waiting until ASP.NET application is accepting connections...");
             var listeningMessage = _process
                 .OutputLinesAsEnumerable
                 .Where(line => line != null)
@@ -70,6 +77,7 @@ namespace Templates.Test.Helpers
             // Verify we have a valid URL to make requests to            
             var listeningUrlString = listeningMessage.Substring(ListeningMessagePrefix.Length);
             _listeningUri = new Uri(listeningUrlString, UriKind.Absolute);
+            output.WriteLine($"Detected that ASP.NET application is accepting connections on {listeningUrlString}");
         }
 
         public void AssertOk(string requestUrl)
@@ -90,7 +98,7 @@ namespace Templates.Test.Helpers
 
         public IWebDriver VisitInBrowser()
         {
-            Console.WriteLine($"Opening browser at {_listeningUri}...");
+            _output.WriteLine($"Opening browser at {_listeningUri}...");
             var driver = WebDriverFactory.CreateWebDriver();
             driver.Navigate().GoToUrl(_listeningUri);
             return driver;

test/Templates.Test/Helpers/ProcessEx.cs

@@ -1,21 +1,22 @@
 using System;
 using System.Collections.Concurrent;
 using System.Collections.Generic;
-using System.Collections.Specialized;
 using System.Diagnostics;
 using System.Text;
-using Xunit;
+using Xunit.Abstractions;
 
 namespace Templates.Test.Helpers
 {
     internal class ProcessEx : IDisposable
     {
+        private readonly ITestOutputHelper _output;
         private readonly Process _process;
         private readonly StringBuilder _stderrCapture;
         private readonly StringBuilder _stdoutCapture;
+        private readonly object _pipeCaptureLock = new object();
         private BlockingCollection<string> _stdoutLines;
 
-        public static ProcessEx Run(string workingDirectory, string command, string args = null, IDictionary<string, string> envVars = null)
+        public static ProcessEx Run(ITestOutputHelper output, string workingDirectory, string command, string args = null, IDictionary<string, string> envVars = null)
         {
             var startInfo = new ProcessStartInfo(command, args)
             {
@@ -36,11 +37,12 @@ namespace Templates.Test.Helpers
 
             var proc = Process.Start(startInfo);
 
-            return new ProcessEx(proc);
+            return new ProcessEx(output, proc);
         }
 
-        public ProcessEx(Process proc)
+        public ProcessEx(ITestOutputHelper output, Process proc)
         {
+            _output = output;
             _stdoutCapture = new StringBuilder();
             _stderrCapture = new StringBuilder();
             _stdoutLines = new BlockingCollection<string>();
@@ -62,14 +64,32 @@ namespace Templates.Test.Helpers
 
         private void OnErrorData(object sender, DataReceivedEventArgs e)
         {
-            _stderrCapture.AppendLine(e.Data);
+            if (e.Data == null)
-            Console.Error.WriteLine(e.Data);
+            {
+                return;
+            }
+
+            lock (_pipeCaptureLock)
+            {
+                _stderrCapture.AppendLine(e.Data);
+            }
+
+            _output.WriteLine("[ERROR] " + e.Data);
         }
 
         private void OnOutputData(object sender, DataReceivedEventArgs e)
         {
-            _stdoutCapture.AppendLine(e.Data);
+            if (e.Data == null)
-            Console.WriteLine(e.Data);
+            {
+                return;
+            }
+
+            lock (_pipeCaptureLock)
+            {
+                _stdoutCapture.AppendLine(e.Data);
+            }
+
+            _output.WriteLine(e.Data);
 
             if (_stdoutLines != null)
             {

test/Templates.Test/Helpers/TemplatePackageInstaller.cs

@@ -1,11 +1,15 @@
 using System;
 using System.IO;
 using System.Linq;
+using Xunit.Abstractions;
 
 namespace Templates.Test.Helpers
 {
     internal static class TemplatePackageInstaller
     {
+        private static object _templatePackagesReinstallationLock = new object();
+        private static bool _haveReinstalledTemplatePackages;
+
         private static readonly string[] _templatePackages = new[]
         {
             "Microsoft.DotNet.Web.ItemTemplates",
@@ -14,19 +18,32 @@ namespace Templates.Test.Helpers
             "Microsoft.AspNetCore.SpaTemplates",
         };
 
-        public static void ReinstallTemplatePackages()
+        public static void EnsureTemplatePackagesWereReinstalled(ITestOutputHelper output)
+        {
+            lock (_templatePackagesReinstallationLock)
+            {
+                if (!_haveReinstalledTemplatePackages)
+                {
+                    ReinstallTemplatePackages(output);
+                    _haveReinstalledTemplatePackages = true;
+                }
+            }
+        }
+
+        private static void ReinstallTemplatePackages(ITestOutputHelper output)
         {
             // Remove any previous or prebundled version of the template packages
             foreach (var packageName in _templatePackages)
             {
                 var proc = ProcessEx.Run(
+                    output,
                     Directory.GetCurrentDirectory(),
                     "dotnet",
                     $"new --uninstall {packageName}");
                 proc.WaitForExit(assertSuccess: true);
             }
 
-            VerifyCannotFindTemplate("ASP.NET Core Empty");
+            VerifyCannotFindTemplate(output, "ASP.NET Core Empty");
 
             // Locate the artifacts directory containing the built template packages
             var solutionDir = FindAncestorDirectoryContaining("Templating.sln");
@@ -36,8 +53,9 @@ namespace Templates.Test.Helpers
             {
                 if (_templatePackages.Any(name => Path.GetFileName(packagePath).StartsWith(name, StringComparison.OrdinalIgnoreCase)))
                 {
-                    Console.WriteLine($"Installing templates package {packagePath}...");
+                    output.WriteLine($"Installing templates package {packagePath}...");
                     var proc = ProcessEx.Run(
+                        output,
                         Directory.GetCurrentDirectory(),
                         "dotnet",
                         $"new --install \"{packagePath}\"");
@@ -46,7 +64,7 @@ namespace Templates.Test.Helpers
             }
         }
 
-        private static void VerifyCannotFindTemplate(string templateName)
+        private static void VerifyCannotFindTemplate(ITestOutputHelper output, string templateName)
         {
             // Verify we really did remove the previous templates
             var tempDir = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString("D"));
@@ -54,6 +72,7 @@ namespace Templates.Test.Helpers
             try
             {
                 var proc = ProcessEx.Run(
+                    output,
                     tempDir,
                     "dotnet",
                     $"new \"{templateName}\"");

test/Templates.Test/Helpers/TemplateTestBase.cs

@@ -4,6 +4,7 @@ using System.Reflection;
 using System.Threading;
 using Templates.Test.Helpers;
 using Xunit;
+using Xunit.Abstractions;
 
 namespace Templates.Test
 {
@@ -11,14 +12,13 @@ namespace Templates.Test
     {
         protected string ProjectName { get; set; }
         protected string TemplateOutputDir { get; private set; }
+        protected ITestOutputHelper Output { get; private set; }
 
-        static TemplateTestBase()
+        public TemplateTestBase(ITestOutputHelper output)
         {
-            TemplatePackageInstaller.ReinstallTemplatePackages();
+            TemplatePackageInstaller.EnsureTemplatePackagesWereReinstalled(output);
-        }
 
-        public TemplateTestBase()
+            Output = output;
-        {
             ProjectName = Guid.NewGuid().ToString().Replace("-", "");
 
             var assemblyPath = GetType().GetTypeInfo().Assembly.CodeBase;
@@ -58,7 +58,7 @@ namespace Templates.Test
                 args += $" -lang {language}";
             }
 
-            ProcessEx.Run(TemplateOutputDir, "dotnet", args).WaitForExit(assertSuccess: true);            
+            ProcessEx.Run(Output, TemplateOutputDir, "dotnet", args).WaitForExit(assertSuccess: true);            
         }
 
         protected void RunNpmInstall()
@@ -66,7 +66,7 @@ namespace Templates.Test
             // The first time this runs on any given CI agent it may take several minutes.
             // If the agent has NPM 5+ installed, it should be quite a lot quicker on
             // subsequent runs because of package caching.
-            ProcessEx.Run(TemplateOutputDir, "cmd", "/c \"npm install\"").WaitForExit(assertSuccess: true);
+            ProcessEx.Run(Output, TemplateOutputDir, "cmd", "/c \"npm install\"").WaitForExit(assertSuccess: true);
         }
 
         protected void AssertDirectoryExists(string path, bool shouldExist)
@@ -107,7 +107,7 @@ namespace Templates.Test
 
         protected AspNetProcess StartAspNetProcess(string targetFrameworkOverride, bool publish = false)
         {
-            return new AspNetProcess(TemplateOutputDir, ProjectName, targetFrameworkOverride, publish);
+            return new AspNetProcess(Output, TemplateOutputDir, ProjectName, targetFrameworkOverride, publish);
         }
 
         public void Dispose()
@@ -117,24 +117,25 @@ namespace Templates.Test
 
         private void DeleteOutputDirectory()
         {
-            var numAttempts = 5;
+            const int NumAttempts = 10;
-            while (true)
+
+            for (var numAttemptsRemaining = NumAttempts; numAttemptsRemaining > 0; numAttemptsRemaining--)
             {
                 try
                 {
                     Directory.Delete(TemplateOutputDir, true);
                     return;
                 }
-                catch (IOException)
+                catch (Exception ex)
                 {
-                    numAttempts--;
+                    if (numAttemptsRemaining > 1)
-                    if (numAttempts > 0)
                     {
-                        Thread.Sleep(2000);
+                        Output.WriteLine($"Failed to delete directory {TemplateOutputDir} because of error {ex.Message}. Will try again {numAttemptsRemaining - 1} more time(s).");
+                        Thread.Sleep(3000);
                     }
                     else
                     {
-                        throw;
+                        Output.WriteLine($"Giving up trying to delete directory {TemplateOutputDir} after {NumAttempts} attempts. Most recent error was: {ex.StackTrace}");
                     }
                 }
             }

test/Templates.Test/MvcTemplateTest.cs

@@ -1,9 +1,14 @@
 using Xunit;
+using Xunit.Abstractions;
 
 namespace Templates.Test
 {
     public class MvcTemplateTest : TemplateTestBase
     {
+        public MvcTemplateTest(ITestOutputHelper output) : base(output)
+        {
+        }
+
         [Theory]
         [InlineData(/* netcoreapp */ null, /* C# */ null)]
         [InlineData("net461", /* C# */ null)]

test/Templates.Test/RazorPagesTemplateTest.cs

@@ -1,9 +1,14 @@
 using Xunit;
+using Xunit.Abstractions;
 
 namespace Templates.Test
 {
     public class RazorPagesTemplateTest : TemplateTestBase
     {
+        public RazorPagesTemplateTest(ITestOutputHelper output) : base(output)
+        {
+        }
+
         [Theory]
         [InlineData(null)]
         [InlineData("net461")]

test/Templates.Test/SpaTemplateTest.cs

@@ -1,11 +1,16 @@
 using OpenQA.Selenium;
 using Templates.Test.Helpers;
 using Xunit;
+using Xunit.Abstractions;
 
 namespace Templates.Test
 {
     public class SpaTemplateTest : TemplateTestBase
     {
+        public SpaTemplateTest(ITestOutputHelper output) : base(output)
+        {
+        }
+
         [Theory]
         [InlineData(null, "angular")]
         [InlineData(null, "react")]

test/Templates.Test/WebApiTemplateTest.cs

@@ -1,9 +1,14 @@
 using Xunit;
+using Xunit.Abstractions;
 
 namespace Templates.Test
 {
     public class WebApiTemplateTest : TemplateTestBase
     {
+        public WebApiTemplateTest(ITestOutputHelper output) : base(output)
+        {
+        }
+
         [Theory]
         [InlineData(null)]
         [InlineData("net461")]