Diagnose more gRPC template hangs

.azure/pipelines/ci.yml

@@ -19,6 +19,8 @@ pr:
     - '*'
 
 variables:
+- name: SkipBuilds
+  value: true
 - name: DOTNET_SKIP_FIRST_TIME_EXPERIENCE
   value: true
 - name: _TeamName
@@ -94,6 +96,7 @@ stages:
   # Code check
   - template: jobs/default-build.yml
     parameters:
+      condition: ne(variables['SkipBuilds'], 'true')
       jobName: Code_check
       jobDisplayName: Code check
       agentOs: Windows
@@ -117,6 +120,7 @@ stages:
   # Build Windows (x64/x86)
   - template: jobs/default-build.yml
     parameters:
+      condition: ne(variables['SkipBuilds'], 'true')
       codeSign: true
       jobName: Windows_build
       jobDisplayName: "Build: Windows x64/x86"
@@ -227,6 +231,7 @@ stages:
   # Build Windows ARM
   - template: jobs/default-build.yml
     parameters:
+      condition: ne(variables['SkipBuilds'], 'true')
       codeSign: true
       jobName: Windows_arm_build
       jobDisplayName: "Build: Windows ARM"
@@ -257,6 +262,7 @@ stages:
   # Build Windows ARM64
   - template: jobs/default-build.yml
     parameters:
+      condition: ne(variables['SkipBuilds'], 'true')
       codeSign: true
       jobName: Windows_64_build
       jobDisplayName: "Build: Windows ARM64"
@@ -289,6 +295,7 @@ stages:
   # Build MacOS
   - template: jobs/default-build.yml
     parameters:
+      condition: ne(variables['SkipBuilds'], 'true')
       jobName: MacOs_x64_build
       jobDisplayName: "Build: macOS"
       agentOs: macOs
@@ -319,6 +326,7 @@ stages:
   # Build Linux x64
   - template: jobs/default-build.yml
     parameters:
+      condition: ne(variables['SkipBuilds'], 'true')
       jobName: Linux_x64_build
       jobDisplayName: "Build: Linux x64"
       agentOs: Linux
@@ -391,6 +399,7 @@ stages:
   # Build Linux ARM
   - template: jobs/default-build.yml
     parameters:
+      condition: ne(variables['SkipBuilds'], 'true')
       jobName: Linux_arm_build
       jobDisplayName: "Build: Linux ARM"
       agentOs: Linux
@@ -422,6 +431,7 @@ stages:
   # Build Linux ARM64
   - template: jobs/default-build.yml
     parameters:
+      condition: ne(variables['SkipBuilds'], 'true')
       jobName: Linux_arm64_build
       jobDisplayName: "Build: Linux ARM64"
       agentOs: Linux
@@ -453,6 +463,7 @@ stages:
   # Build Linux Musl x64
   - template: jobs/default-build.yml
     parameters:
+      condition: ne(variables['SkipBuilds'], 'true')
       jobName: Linux_musl_x64_build
       jobDisplayName: "Build: Linux Musl x64"
       agentOs: Linux
@@ -487,6 +498,7 @@ stages:
   # Build Linux Musl ARM64
   - template: jobs/default-build.yml
     parameters:
+      condition: ne(variables['SkipBuilds'], 'true')
       jobName: Linux_musl_arm64_build
       jobDisplayName: "Build: Linux Musl ARM64"
       agentOs: Linux
@@ -521,7 +533,7 @@ stages:
   # Test jobs
   - template: jobs/default-build.yml
     parameters:
-      condition: ne(variables['SkipTests'], 'true')
+      condition: ne(variables['SkipBuilds'], 'true')
       jobName: Windows_Test
       jobDisplayName: "Test: Windows Server 2016 x64"
       agentOs: Windows
@@ -556,7 +568,7 @@ stages:
 
   - template: jobs/default-build.yml
     parameters:
-      condition: ne(variables['SkipTests'], 'true')
+      condition: ne(variables['SkipBuilds'], 'true')
       jobName: Windows_Templates_Test
       jobDisplayName: "Test: Templates - Windows Server 2016 x64"
       agentOs: Windows
@@ -592,7 +604,6 @@ stages:
 
   - template: jobs/default-build.yml
     parameters:
-      condition: ne(variables['SkipTests'], 'true')
       jobName: MacOS_Test
       jobDisplayName: "Test: macOS 10.13"
       agentOs: macOS
@@ -615,6 +626,7 @@ stages:
           testResultsFormat: 'xUnit'
           testResultsFiles: '*.xml'
           searchFolder: '$(Build.SourcesDirectory)/artifacts/TestResults/$(_BuildConfig)/Quarantined'
+        condition: always()
       artifacts:
       - name: MacOS_Test_Logs
         path: artifacts/log/
@@ -627,7 +639,7 @@ stages:
 
   - template: jobs/default-build.yml
     parameters:
-      condition: ne(variables['SkipTests'], 'true')
+      condition: ne(variables['SkipBuilds'], 'true')
       jobName: Linux_Test
       jobDisplayName: "Test: Ubuntu 16.04 x64"
       agentOs: Linux
@@ -665,7 +677,7 @@ stages:
   # Helix x64
   - template: jobs/default-build.yml
     parameters:
-      condition: in(variables['Build.Reason'], 'PullRequest')
+      condition: and(in(variables['Build.Reason'], 'PullRequest'), ne(variables['SkipBuilds'], 'true'))
       jobName: Helix_x64
       jobDisplayName: 'Tests: Helix x64'
       agentOs: Windows

src/ProjectTemplates/test/GrpcTemplateTest.cs

@@ -6,6 +6,7 @@
 using System.Runtime.InteropServices;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Testing;
+using Microsoft.Extensions.Logging;
 using Templates.Test.Helpers;
 using Xunit;
 using Xunit.Abstractions;
@@ -25,7 +26,7 @@ public GrpcTemplateTest(ProjectFactoryFixture projectFactory, ITestOutputHelper
         public ProjectFactoryFixture ProjectFactory { get; }
         public ITestOutputHelper Output { get; }
 
-        [ConditionalFact(Skip = "This test run for over an hour")]
+        [ConditionalFact()]
         [SkipOnHelix("Not supported queues", Queues = "Windows.7.Amd64;Windows.7.Amd64.Open;OSX.1014.Amd64;OSX.1014.Amd64.Open")]
         [QuarantinedTest("https://github.com/dotnet/aspnetcore/issues/19716")]
         public async Task GrpcTemplate()
@@ -35,23 +36,31 @@ public async Task GrpcTemplate()
             using var testLog = assemblyLog.StartTestLog(Output, nameof(GrpcTemplateTest), out var loggerFactory);
             var logger = loggerFactory.CreateLogger("TestLogger");
 
+            logger.LogInformation("GrpcTemplateTest - Test start");
+
             Project = await ProjectFactory.GetOrCreateProject("grpc", Output);
+            logger.LogInformation("GrpcTemplateTest - Initialize project");
 
             var createResult = await Project.RunDotNetNewAsync("grpc");
             Assert.True(0 == createResult.ExitCode, ErrorMessages.GetFailedProcessMessage("create/restore", Project, createResult));
+            logger.LogInformation("GrpcTemplateTest - Created project");
 
             var publishResult = await Project.RunDotNetPublishAsync();
             Assert.True(0 == publishResult.ExitCode, ErrorMessages.GetFailedProcessMessage("publish", Project, publishResult));
+            logger.LogInformation("GrpcTemplateTest - published project");
 
             var buildResult = await Project.RunDotNetBuildAsync();
             Assert.True(0 == buildResult.ExitCode, ErrorMessages.GetFailedProcessMessage("build", Project, buildResult));
+            logger.LogInformation("GrpcTemplateTest - built project");
 
             var isOsx = RuntimeInformation.IsOSPlatform(OSPlatform.OSX);
             var isWindowsOld = RuntimeInformation.IsOSPlatform(OSPlatform.Windows) && Environment.OSVersion.Version < new Version(6, 2);
             var unsupported = isOsx || isWindowsOld;
 
+            logger.LogInformation("GrpcTemplateTest - Starting built project");
             using (var serverProcess = Project.StartBuiltProjectAsync(hasListeningUri: !unsupported, logger: logger))
             {
+                logger.LogInformation("GrpcTemplateTest - Verifing built project results");
                 // These templates are HTTPS + HTTP/2 only which is not supported on Mac due to missing ALPN support.
                 // https://github.com/dotnet/aspnetcore/issues/11061
                 if (isOsx)
@@ -78,6 +87,7 @@ public async Task GrpcTemplate()
 
             using (var aspNetProcess = Project.StartPublishedProjectAsync(hasListeningUri: !unsupported))
             {
+                logger.LogInformation("GrpcTemplateTest - Verifing published project results");
                 // These templates are HTTPS + HTTP/2 only which is not supported on Mac due to missing ALPN support.
                 // https://github.com/dotnet/aspnetcore/issues/11061
                 if (isOsx)

src/ProjectTemplates/test/Helpers/AspNetProcess.cs

@@ -42,6 +42,8 @@ public AspNetProcess(
             bool hasListeningUri = true,
             ILogger logger = null)
         {
+            logger?.LogInformation($"AspNetProcess - initializing");
+
             _output = output;
             _httpClient = new HttpClient(new HttpClientHandler()
             {
@@ -54,7 +56,11 @@ public AspNetProcess(
                 Timeout = TimeSpan.FromMinutes(2)
             };
 
-            EnsureDevelopmentCertificates();
+            logger?.LogInformation($"AspNetProcess - http client created");
+
+            EnsureDevelopmentCertificates(logger);
+
+            logger?.LogInformation($"AspNetProcess - development certificates resolved");
 
             output.WriteLine("Running ASP.NET application...");
 
@@ -74,10 +80,12 @@ public AspNetProcess(
             }
         }
 
-        internal static void EnsureDevelopmentCertificates()
+        internal static void EnsureDevelopmentCertificates(ILogger logger = null)
         {
+            logger?.LogInformation($"AspNetProcess/EnsureDevelopmentCertificates - start");
             var now = DateTimeOffset.Now;
             new CertificateManager().EnsureAspNetCoreHttpsDevelopmentCertificate(now, now.AddYears(1));
+            logger?.LogInformation($"AspNetProcess/EnsureDevelopmentCertificates - end");
         }
 
         public void VisitInBrowser(IWebDriver driver)

src/ProjectTemplates/test/Helpers/Project.cs

@@ -27,11 +27,11 @@ public class Project
         public static bool IsCIEnvironment => typeof(Project).Assembly.GetCustomAttributes<AssemblyMetadataAttribute>()
             .Any(a => a.Key == "ContinuousIntegrationBuild");
 
-        public static string ArtifactsLogDir => (string.IsNullOrEmpty(Environment.GetEnvironmentVariable("HELIX_DIR"))) 
+        public static string ArtifactsLogDir => (string.IsNullOrEmpty(Environment.GetEnvironmentVariable("HELIX_DIR")))
             ? GetAssemblyMetadata("ArtifactsLogDir")
             : Path.Combine(Environment.GetEnvironmentVariable("HELIX_DIR"), "logs");
-        
-        public static string DotNetEfFullPath => (string.IsNullOrEmpty(Environment.GetEnvironmentVariable("DotNetEfFullPath"))) 
+
+        public static string DotNetEfFullPath => (string.IsNullOrEmpty(Environment.GetEnvironmentVariable("DotNetEfFullPath")))
             ? typeof(ProjectFactoryFixture).Assembly.GetCustomAttributes<AssemblyMetadataAttribute>()
                 .First(attribute => attribute.Key == "DotNetEfFullPath")
                 .Value
@@ -221,6 +221,9 @@ internal AspNetProcess StartBuiltProjectAsync(bool hasListeningUri = true, ILogg
             };
 
             var projectDll = Path.Combine(TemplateBuildDir, $"{ProjectName}.dll");
+
+            logger?.LogInformation("Project - creating AspNetProcess");
+
             return new AspNetProcess(Output, TemplateOutputDir, projectDll, environment, hasListeningUri: hasListeningUri, logger: logger);
         }
 
@@ -309,7 +312,7 @@ private async Task<ProcessEx> RestoreAsync(ITestOutputHelper output, string work
         internal async Task<ProcessEx> RunDotNetEfCreateMigrationAsync(string migrationName)
         {
             var args = $"--verbose --no-build migrations add {migrationName}";
-            
+
             // Only run one instance of 'dotnet new' at once, as a workaround for
             // https://github.com/aspnet/templating/issues/63
             await DotNetNewLock.WaitAsync();
@@ -324,7 +327,7 @@ internal async Task<ProcessEx> RunDotNetEfCreateMigrationAsync(string migrationN
                 {
                     command = "dotnet-ef";
                 }
-                
+
                 var result = ProcessEx.Run(Output, TemplateOutputDir, command, args);
                 await result.Exited;
                 return result;
@@ -353,7 +356,7 @@ internal async Task<ProcessEx> RunDotNetEfUpdateDatabaseAsync()
                 {
                     command = "dotnet-ef";
                 }
-                
+
                 var result = ProcessEx.Run(Output, TemplateOutputDir, command, args);
                 await result.Exited;
                 return result;