Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Better logging for named pipe #11144

Merged
merged 1 commit into from
Nov 5, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Expand Down Expand Up @@ -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");
Expand Down Expand Up @@ -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)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand All @@ -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
Expand All @@ -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;
Expand All @@ -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;
Expand Down Expand Up @@ -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)
Expand Down
24 changes: 20 additions & 4 deletions src/Razor/src/rzls/NamedPipeBasedRazorProjectInfoDriver.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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");
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should this log the exception? I have no idea why this would fail, and need to be re-tried, but seems like the logs could help tell us.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

tbh it could be right now the only way it can throw is by getting an Assumes.Unreachable which isn't very actionable.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In a perfect world, Assumed.Unreachable should never be hit. It should just be used to make the compiler happy. If it's being hit, then expectations are incorrect.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree with that for sure, but trying to figure out why the expectations are incorrect is currently the hard part.

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");
Expand All @@ -72,9 +91,6 @@ private async Task ReadFromStreamAsync(CancellationToken cancellationToken)
}

break;

default:
throw Assumes.NotReachable();
}
}
catch (Exception ex)
Expand Down
Loading