Better logging for named pipe (#11144)

Add logging on the server side for why a project isn't being serialized.

Reduce some of the logging on the client side if it gets into a bad state. Log once for first bad read and once when it gets to a point where we think we returned to a good state.

src/Razor/src/Microsoft.AspNetCore.Razor.ExternalAccess.RoslynWorkspace/RazorWorkspaceListenerBase.cs

@@ -195,7 +195,7 @@ void RemoveProject(Project project)
         {
             // Remove project is called from Workspace.Changed, while other notifications of _projectsWithDynamicFile
             // are handled with NotifyDynamicFile. Use ImmutableInterlocked here to be sure the updates happen
-            // in a thread safe manner since those are not assumed to be the same thread. 
+            // in a thread safe manner since those are not assumed to be the same thread.
             if (ImmutableInterlocked.TryRemove(ref _projectsWithDynamicFile, project.Id, out var _))
             {
                 var intermediateOutputPath = Path.GetDirectoryName(project.CompilationOutputInfo.AssemblyPath);
@@ -227,7 +227,7 @@ private protected async virtual ValueTask ProcessWorkAsync(ImmutableArray<Work>
 
         cancellationToken.ThrowIfCancellationRequested();
 
-        // Early bail check for if we are disposed or somewhere in the middle of disposal 
+        // Early bail check for if we are disposed or somewhere in the middle of disposal
         if (_disposed || stream is null || solution is null)
         {
             _logger.LogTrace("Skipping work due to disposal");
@@ -279,15 +279,15 @@ private static async Task ProcessWorkCoreAsync(ImmutableArray<Work> work, Stream
     private static async Task ReportUpdateProjectAsync(Stream stream, Project project, ILogger logger, CancellationToken cancellationToken)
     {
         logger.LogTrace("Serializing information for {projectId}", project.Id);
-        var projectInfo = await RazorProjectInfoFactory.ConvertAsync(project, cancellationToken).ConfigureAwait(false);
-        if (projectInfo is null)
+        var result = await RazorProjectInfoFactory.ConvertAsync(project, cancellationToken).ConfigureAwait(false);
+        if (!result.Succeeded)
         {
-            logger.LogTrace("Skipped writing data for {projectId}", project.Id);
+            logger.LogTrace("Skipped writing data for {projectId} because of '{reason}'", project.Id, result.Reason);
             return;
         }
 
         stream.WriteProjectInfoAction(ProjectInfoAction.Update);
-        await stream.WriteProjectInfoAsync(projectInfo, cancellationToken).ConfigureAwait(false);
+        await stream.WriteProjectInfoAsync(result.ProjectInfo, cancellationToken).ConfigureAwait(false);
     }
 
     private static Task ReportRemovalAsync(Stream stream, RemovalWork unit, ILogger logger, CancellationToken cancellationToken)

src/Razor/src/Microsoft.AspNetCore.Razor.ProjectEngineHost/Utilities/RazorProjectInfoFactory.cs

@@ -24,6 +24,12 @@ namespace Microsoft.AspNetCore.Razor.Utilities;
 
 internal static class RazorProjectInfoFactory
 {
+    internal readonly record struct ConversionResult(RazorProjectInfo? ProjectInfo, string? Reason)
+    {
+        [MemberNotNullWhen(true, nameof(ProjectInfo))]
+        public bool Succeeded => ProjectInfo is not null;
+    }
+
     private static readonly StringComparison s_stringComparison;
 
     static RazorProjectInfoFactory()
@@ -33,18 +39,18 @@ static RazorProjectInfoFactory()
             : StringComparison.OrdinalIgnoreCase;
     }
 
-    public static async Task<RazorProjectInfo?> ConvertAsync(Project project, CancellationToken cancellationToken)
+    public static async Task<ConversionResult> ConvertAsync(Project project, CancellationToken cancellationToken)
     {
         var projectPath = Path.GetDirectoryName(project.FilePath);
         if (projectPath is null)
         {
-            return null;
+            return new(null, "Failed to get directory name from project path");
         }
 
         var intermediateOutputPath = Path.GetDirectoryName(project.CompilationOutputInfo.AssemblyPath);
         if (intermediateOutputPath is null)
         {
-            return null;
+            return new(null, "Failed to get intermediate output path");
         }
 
         // First, lets get the documents, because if there aren't any, we can skip out early
@@ -53,7 +59,7 @@ static RazorProjectInfoFactory()
         // Not a razor project
         if (documents.Length == 0)
         {
-            return null;
+            return new(null, "No razor documents in project");
         }
 
         var csharpParseOptions = project.ParseOptions as CSharpParseOptions ?? CSharpParseOptions.Default;
@@ -63,7 +69,7 @@ static RazorProjectInfoFactory()
         var compilation = await project.GetCompilationAsync(cancellationToken).ConfigureAwait(false);
         if (compilation is null)
         {
-            return null;
+            return new(null, "Failed to get compilation for project");
         }
 
         var options = project.AnalyzerOptions.AnalyzerConfigOptionsProvider;
@@ -93,14 +99,16 @@ static RazorProjectInfoFactory()
 
         var projectWorkspaceState = ProjectWorkspaceState.Create(tagHelpers);
 
-        return new RazorProjectInfo(
+        var projectInfo = new RazorProjectInfo(
             projectKey: new ProjectKey(intermediateOutputPath),
             filePath: project.FilePath!,
             configuration: configuration,
             rootNamespace: defaultNamespace,
             displayName: project.Name,
             projectWorkspaceState: projectWorkspaceState,
             documents: documents);
+
+        return new(projectInfo, null);
     }
 
     private static RazorConfiguration ComputeRazorConfigurationOptions(AnalyzerConfigOptionsProvider options, Compilation compilation, out string defaultNamespace)

src/Razor/src/rzls/NamedPipeBasedRazorProjectInfoDriver.cs

@@ -46,15 +46,34 @@ protected override void OnDispose()
     private async Task ReadFromStreamAsync(CancellationToken cancellationToken)
     {
         Logger.LogTrace($"Starting read from named pipe.");
+        var failedActionReads = 0;
 
         while (
             _namedPipe is { IsConnected: true } &&
             !cancellationToken.IsCancellationRequested)
         {
+            ProjectInfoAction? projectInfoAction;
+            try
+            {
+                projectInfoAction = _namedPipe.ReadProjectInfoAction();
+            }
+            catch
+            {
+                if (failedActionReads++ > 0)
+                {
+                    throw;
+                }
+
+                Logger.LogError("Failed to read ProjectInfoAction from stream");
+                continue;
+            }
+
+            Logger.LogInformation($"Failed {failedActionReads} times but things may be back on track");
+            failedActionReads = 0;
 
             try
             {
-                switch (_namedPipe.ReadProjectInfoAction())
+                switch (projectInfoAction)
                 {
                     case ProjectInfoAction.Remove:
                         Logger.LogTrace($"Attempting to read project id for removal");
@@ -72,9 +91,6 @@ private async Task ReadFromStreamAsync(CancellationToken cancellationToken)
                         }
 
                         break;
-
-                    default:
-                        throw Assumes.NotReachable();
                 }
             }
             catch (Exception ex)