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.

Sign up for GitHub

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

Jump to bottom

BuildCheck does not run on restore #10018

Closed
wants to merge 17 commits into from
Closed

BuildCheck does not run on restore #10018

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
17 commits
Select commit Hold shift + click to select a range
5b33d8f
First pass on disabling BuildCheck on restore
maridematte Mar 21, 2024
916d822
BuildCheck doesn't run on restore
maridematte Mar 22, 2024
8363efc
Addressed PR comments
maridematte Apr 9, 2024
7d223bc
Modified how logger registers isRestore
maridematte Apr 15, 2024
f72913e
Merge branch 'main' into 9747
maridematte Apr 16, 2024
08b0cd1
Fixed merge errors
maridematte Apr 16, 2024
288adff
Clean merge v2
maridematte Apr 16, 2024
e3ea5ba
Updated existing tests
maridematte Apr 18, 2024
f19e200
Added test
maridematte Apr 18, 2024
15c61c8
Fix failing tests
maridematte Apr 19, 2024
b047dd4
Clean up merge, one again
maridematte Apr 19, 2024
a014fdb
changed case on test file
maridematte Apr 22, 2024
d0c84b0
Solved merge conflicts
maridematte Apr 24, 2024
8da2ae4
Merge main
maridematte Apr 25, 2024
f0c8c19
Reqorked on ConnectorLogger due changes
maridematte Apr 25, 2024
5626302
Changed isRestore reset to project evaluation started
maridematte Apr 29, 2024
39cadf8
Added documentation
maridematte Apr 29, 2024
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
2 changes: 1 addition & 1 deletion src/Build.UnitTests/BackEnd/MockLoggingService.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -496,7 +496,7 @@ public BuildEventContext CreateProjectCacheBuildEventContext(int submissionId, i
=> new BuildEventContext(0, 0, 0, 0, 0, 0, 0);

/// <inheritdoc />
public void LogProjectEvaluationStarted(BuildEventContext eventContext, string projectFile)
public void LogProjectEvaluationStarted(BuildEventContext eventContext, string projectFile, bool isRestore)
{
}

Expand Down
5 changes: 3 additions & 2 deletions src/Build/BackEnd/Components/Logging/EvaluationLoggingContext.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
// The .NET Foundation licenses this file to you under the MIT license.

using System.Collections;
using System.Collections.Generic;
using Microsoft.Build.BackEnd.Logging;
using Microsoft.Build.Framework;
using Microsoft.Build.Framework.Profiler;
Expand All @@ -27,9 +28,9 @@ public EvaluationLoggingContext(ILoggingService loggingService, BuildEventContex
IsValid = true;
}

public void LogProjectEvaluationStarted()
public void LogProjectEvaluationStarted(bool isRestore)
{
LoggingService.LogProjectEvaluationStarted(BuildEventContext, _projectFile);
LoggingService.LogProjectEvaluationStarted(BuildEventContext, _projectFile, isRestore);
}

/// <summary>
Expand Down
3 changes: 2 additions & 1 deletion src/Build/BackEnd/Components/Logging/ILoggingService.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -485,8 +485,9 @@ MessageImportance MinimumRequiredMessageImportance
/// </summary>
/// <param name="eventContext">The event context to use for logging</param>
/// <param name="projectFile">Project file being built</param>
/// <param name="isRestore">If the project is currently in restore phase </param>
/// <returns>The evaluation event context for the project.</returns>
void LogProjectEvaluationStarted(BuildEventContext eventContext, string projectFile);
void LogProjectEvaluationStarted(BuildEventContext eventContext, string projectFile, bool isRestore);

/// <summary>
/// Logs that a project evaluation has finished
Expand Down
5 changes: 3 additions & 2 deletions src/Build/BackEnd/Components/Logging/LoggingServiceLogMethods.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -444,14 +444,15 @@ public BuildEventContext CreateProjectCacheBuildEventContext(
}

/// <inheritdoc />
public void LogProjectEvaluationStarted(BuildEventContext projectEvaluationEventContext, string projectFile)
public void LogProjectEvaluationStarted(BuildEventContext projectEvaluationEventContext, string projectFile, bool isRestore)
{
ProjectEvaluationStartedEventArgs evaluationEvent =
new ProjectEvaluationStartedEventArgs(ResourceUtilities.GetResourceString("EvaluationStarted"),
projectFile)
{
BuildEventContext = projectEvaluationEventContext,
ProjectFile = projectFile
ProjectFile = projectFile,
IsRestore = isRestore
};

ProcessLoggingEvent(evaluationEvent);
Expand Down
16 changes: 9 additions & 7 deletions src/Build/BackEnd/Components/RequestBuilder/RequestBuilder.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1105,9 +1105,9 @@ private async Task<BuildResult> BuildProject()
ErrorUtilities.VerifyThrow(_targetBuilder != null, "Target builder is null");

// We consider this the entrypoint for the project build for purposes of BuildCheck processing

var buildCheckManager = (_componentHost.GetComponent(BuildComponentType.BuildCheckManagerProvider) as IBuildCheckManagerProvider)!.Instance;
buildCheckManager.SetDataSource(BuildCheckDataSource.BuildExecution);
var propertyEntry = _requestEntry.RequestConfiguration.GlobalProperties[MSBuildConstants.MSBuildIsRestoring];
Copy link
Member

Choose a reason for hiding this comment

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

I don't think I understand, since we have this, why we need the change to the evaluation-started event. Can you go over that again?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

There are two points in BuildCheck that actually run the analyzer. One of them is through the RequestBuilder which works on the worker nodes. And through the BuildCheckConnectorLogger which runs on the main node. The modification to the evaluation-started event is to get information about the restore phase to the connector logger.

IBuildCheckManager buildCheckManager = propertyEntry is not null ? null : (_componentHost.GetComponent(BuildComponentType.BuildCheckManagerProvider) as IBuildCheckManagerProvider)!.Instance;
buildCheckManager?.SetDataSource(BuildCheckDataSource.BuildExecution);

// Make sure it is null before loading the configuration into the request, because if there is a problem
// we do not wand to have an invalid projectLoggingContext floating around. Also if this is null the error will be
Expand All @@ -1121,10 +1121,12 @@ private async Task<BuildResult> BuildProject()
// Load the project
if (!_requestEntry.RequestConfiguration.IsLoaded)
{
buildCheckManager.StartProjectEvaluation(

buildCheckManager?.StartProjectEvaluation(
BuildCheckDataSource.BuildExecution,
_requestEntry.Request.ParentBuildEventContext,
_requestEntry.RequestConfiguration.ProjectFullPath);


_requestEntry.RequestConfiguration.LoadProjectIntoConfiguration(
_componentHost,
Expand All @@ -1146,13 +1148,13 @@ private async Task<BuildResult> BuildProject()
}
finally
{
buildCheckManager.EndProjectEvaluation(
buildCheckManager?.EndProjectEvaluation(
BuildCheckDataSource.BuildExecution,
_requestEntry.Request.ParentBuildEventContext);
}

_projectLoggingContext = _nodeLoggingContext.LogProjectStarted(_requestEntry);
buildCheckManager.StartProjectRequest(
buildCheckManager?.StartProjectRequest(
BuildCheckDataSource.BuildExecution,
_requestEntry.Request.ParentBuildEventContext);

Expand Down Expand Up @@ -1223,7 +1225,7 @@ private async Task<BuildResult> BuildProject()
}
finally
{
buildCheckManager.EndProjectRequest(
buildCheckManager?.EndProjectRequest(
BuildCheckDataSource.BuildExecution,
_requestEntry.Request.ParentBuildEventContext);
}
Expand Down
36 changes: 34 additions & 2 deletions src/Build/BuildCheck/Infrastructure/BuildCheckConnectorLogger.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
using Microsoft.Build.BuildCheck.Acquisition;
using Microsoft.Build.Experimental.BuildCheck;
using Microsoft.Build.Framework;
using Microsoft.Build.Shared;
using static Microsoft.Build.BuildCheck.Infrastructure.BuildCheckManagerProvider;

namespace Microsoft.Build.BuildCheck.Infrastructure;
Expand All @@ -31,6 +32,8 @@ internal BuildCheckConnectorLogger(

public string? Parameters { get; set; }

private bool isRestore = false;

public void Initialize(IEventSource eventSource)
{
eventSource.AnyEventRaised += EventSource_AnyEventRaised;
Expand All @@ -48,6 +51,11 @@ public void Shutdown()

private void HandleProjectEvaluationFinishedEvent(ProjectEvaluationFinishedEventArgs eventArgs)
{
if (isRestore)
{
return;
}

if (!IsMetaProjFile(eventArgs.ProjectFile))
{
_buildCheckManager.ProcessEvaluationFinishedEventArgs(
Expand All @@ -60,6 +68,16 @@ private void HandleProjectEvaluationFinishedEvent(ProjectEvaluationFinishedEvent

private void HandleProjectEvaluationStartedEvent(ProjectEvaluationStartedEventArgs eventArgs)
{
if (eventArgs.IsRestore)
{
isRestore = true;
return;
}
if (isRestore)
{
isRestore = false;
Copy link
Member

Choose a reason for hiding this comment

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

This doesn't make sense to me, won't there be a bunch of ProjectFinished events that will fire one after the other, causing the first one to unset this and the others to do check stuff?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yeah, I figured that out after I ran this for a bit. I had hoped the event was just fired once. Is there an event that is fired at the end of the restore phase that I can use to to control the flow on the connector logger?

Copy link
Member

Choose a reason for hiding this comment

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

If we are relying on the restore happen fully before the build - then the first ProjectEvaluationStartedEventArgs that is not marked with IsRestore denotes the start of the build after the restore.

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 changed the isRestore reset to happen when we receive another ProjectEvaluationStartedEventArgs event.

}

if (!IsMetaProjFile(eventArgs.ProjectFile))
{
_buildCheckManager.StartProjectEvaluation(BuildCheckDataSource.EventArgs, eventArgs.BuildEventContext!, eventArgs.ProjectFile!);
Expand Down Expand Up @@ -100,8 +118,22 @@ private void EventSource_BuildFinished(object sender, BuildFinishedEventArgs e)
{
{ typeof(ProjectEvaluationFinishedEventArgs), (BuildEventArgs e) => HandleProjectEvaluationFinishedEvent((ProjectEvaluationFinishedEventArgs) e) },
{ typeof(ProjectEvaluationStartedEventArgs), (BuildEventArgs e) => HandleProjectEvaluationStartedEvent((ProjectEvaluationStartedEventArgs) e) },
{ typeof(ProjectStartedEventArgs), (BuildEventArgs e) => _buildCheckManager.StartProjectRequest(BuildCheckDataSource.EventArgs, e.BuildEventContext!) },
{ typeof(ProjectFinishedEventArgs), (BuildEventArgs e) => _buildCheckManager.EndProjectRequest(BuildCheckDataSource.EventArgs, e.BuildEventContext!) },
{ typeof(ProjectStartedEventArgs), (BuildEventArgs e) =>
{
if (!isRestore)
{
_buildCheckManager.StartProjectRequest(BuildCheckDataSource.EventArgs, e.BuildEventContext!);
Copy link
Member

Choose a reason for hiding this comment

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

super-nit: Indentation

}
}
},
{ typeof(ProjectFinishedEventArgs), (BuildEventArgs e) =>
{
if (!isRestore)
{
_buildCheckManager.EndProjectRequest(BuildCheckDataSource.EventArgs, e.BuildEventContext!);
}
}
},
{ typeof(BuildCheckTracingEventArgs), (BuildEventArgs e) => _stats.Merge(((BuildCheckTracingEventArgs)e).TracingData, (span1, span2) => span1 + span2) },
{ typeof(BuildCheckAcquisitionEventArgs), (BuildEventArgs e) => _buildCheckManager.ProcessAnalyzerAcquisition(((BuildCheckAcquisitionEventArgs)e).ToAnalyzerAcquisitionData(), e.BuildEventContext!) },
};
Expand Down
2 changes: 1 addition & 1 deletion src/Build/Evaluation/Evaluator.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -626,7 +626,7 @@ private void Evaluate()
}
}

_evaluationLoggingContext.LogProjectEvaluationStarted();
_evaluationLoggingContext.LogProjectEvaluationStarted(_data.GlobalPropertiesDictionary[MSBuildConstants.MSBuildIsRestoring] is not null); ;
Copy link
Member

Choose a reason for hiding this comment

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

We currently set the property only to true but it's not unconceivable that at some point someone would want to set it to false to mean "we're not restoring". For future proofing, would you consider parsing the value instead of just checking that the prop is defined?


ErrorUtilities.VerifyThrow(_data.EvaluationId != BuildEventContext.InvalidEvaluationId, "Evaluation should produce an evaluation ID");

Expand Down
108 changes: 59 additions & 49 deletions src/BuildCheck.UnitTests/EndToEndTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -35,32 +35,60 @@ public EndToEndTests(ITestOutputHelper output)
[InlineData(false, false)]
public void SampleAnalyzerIntegrationTest(bool buildInOutOfProcessNode, bool analysisRequested)
{
string contents = $"""
<Project Sdk="Microsoft.NET.Sdk" DefaultTargets="Hello">

TransientTestFile projectFile = SetupTestFiles();
_env.SetEnvironmentVariable("MSBUILDNOINPROCNODE", buildInOutOfProcessNode ? "1" : "0");
_env.SetEnvironmentVariable("MSBUILDLOGPROPERTIESANDITEMSAFTEREVALUATION", "1");
string output = RunnerUtilities.ExecBootstrapedMSBuild(
$"{Path.GetFileName(projectFile.Path)} /m:1 /p:BuildProjectReferences=false -nr:False -restore" +
(analysisRequested ? " -analyze" : string.Empty), out bool success, false, _env.Output);
_env.Output.WriteLine(output);
success.ShouldBeTrue();
// The conflicting outputs warning appears - but only if analysis was requested
if (analysisRequested)
{
output.ShouldContain("BC0101");
}
else
{
output.ShouldNotContain("BC0101");
}
}

[Fact]
public void NoRunOnRestore()
{
TransientTestFile projectFile = SetupTestFiles();
string output = RunnerUtilities.ExecBootstrapedMSBuild(
$"{Path.GetFileName(projectFile.Path)} /m:1 -nr:False -analyze -t:restore", out bool success);
_env.Output.WriteLine(output);
success.ShouldBeTrue();
output.ShouldNotContain("BC0101");
}

private TransientTestFile SetupTestFiles()
{
{
string contents = $"""
<Project Sdk="Microsoft.NET.Sdk" DefaultTargets="ResolveProjectReferences">
<PropertyGroup>
<OutputType>Exe</OutputType>
<TargetFramework>net8.0</TargetFramework>
<ImplicitUsings>enable</ImplicitUsings>
<Nullable>enable</Nullable>
<OutputType>Exe</OutputType>
<TargetFramework>net8.0</TargetFramework>
<ImplicitUsings>enable</ImplicitUsings>
<Nullable>enable</Nullable>
</PropertyGroup>

<PropertyGroup Condition="$(Test) == true">
<TestProperty>Test</TestProperty>
<TestProperty>Test</TestProperty>
</PropertyGroup>

<ItemGroup>
<ProjectReference Include=".\FooBar-Copy.csproj" />
<ProjectReference Include=".\FooBar-Copy.csproj" />
</ItemGroup>

<Target Name="Hello">
<Message Importance="High" Condition="$(Test2) == true" Text="XYZABC" />
</Target>


</Project>
""";

string contents2 = $"""
string contents2 = $"""
<Project Sdk="Microsoft.NET.Sdk">

<PropertyGroup>
Expand All @@ -77,24 +105,21 @@ public void SampleAnalyzerIntegrationTest(bool buildInOutOfProcessNode, bool ana
<ItemGroup>
<Reference Include="bin/foo.dll" />
</ItemGroup>

<Target Name="Hello">
<Message Importance="High" Condition="$(Test2) == true" Text="XYZABC" />
</Target>

</Project>
""";
TransientTestFolder workFolder = _env.CreateFolder(createFolder: true);
TransientTestFile projectFile = _env.CreateFile(workFolder, "FooBar.csproj", contents);
TransientTestFile projectFile2 = _env.CreateFile(workFolder, "FooBar-Copy.csproj", contents2);

// var cache = new SimpleProjectRootElementCache();
// ProjectRootElement xml = ProjectRootElement.OpenProjectOrSolution(projectFile.Path, /*unused*/null, /*unused*/null, cache, false /*Not explicitly loaded - unused*/);
TransientTestFolder workFolder = _env.CreateFolder(createFolder: true);
TransientTestFile projectFile = _env.CreateFile(workFolder, "FooBar.csproj", contents);
TransientTestFile projectFile2 = _env.CreateFile(workFolder, "FooBar-Copy.csproj", contents2);

// var cache = new SimpleProjectRootElementCache();
// ProjectRootElement xml = ProjectRootElement.OpenProjectOrSolution(projectFile.Path, /*unused*/null, /*unused*/null, cache, false /*Not explicitly loaded - unused*/);


TransientTestFile config = _env.CreateFile(workFolder, "editorconfig.json",
/*lang=json,strict*/
"""
TransientTestFile config = _env.CreateFile(workFolder, "editorconfig.json",
/*lang=json,strict*/
"""
{
"BC0101": {
"IsEnabled": true,
Expand All @@ -112,26 +137,11 @@ public void SampleAnalyzerIntegrationTest(bool buildInOutOfProcessNode, bool ana
}
""");

// OSX links /var into /private, which makes Path.GetTempPath() return "/var..." but Directory.GetCurrentDirectory return "/private/var...".
// This discrepancy breaks path equality checks in analyzers if we pass to MSBuild full path to the initial project.
// See if there is a way of fixing it in the engine - tracked: https://github.com/orgs/dotnet/projects/373/views/1?pane=issue&itemId=55702688.
_env.SetCurrentDirectory(Path.GetDirectoryName(projectFile.Path));

_env.SetEnvironmentVariable("MSBUILDNOINPROCNODE", buildInOutOfProcessNode ? "1" : "0");
_env.SetEnvironmentVariable("MSBUILDLOGPROPERTIESANDITEMSAFTEREVALUATION", "1");
string output = RunnerUtilities.ExecBootstrapedMSBuild(
$"{Path.GetFileName(projectFile.Path)} /m:1 -nr:False -restore" +
(analysisRequested ? " -analyze" : string.Empty), out bool success, false, _env.Output);
_env.Output.WriteLine(output);
success.ShouldBeTrue();
// The conflicting outputs warning appears - but only if analysis was requested
if (analysisRequested)
{
output.ShouldContain("BC0101");
}
else
{
output.ShouldNotContain("BC0101");
// OSX links /var into /private, which makes Path.GetTempPath() return "/var..." but Directory.GetCurrentDirectory return "/private/var...".
// This discrepancy breaks path equality checks in analyzers if we pass to MSBuild full path to the initial project.
// See if there is a way of fixing it in the engine - tracked: https://github.com/orgs/dotnet/projects/373/views/1?pane=issue&itemId=55702688.
_env.SetCurrentDirectory(Path.GetDirectoryName(projectFile.Path));
return (projectFile);
}
}
}
5 changes: 5 additions & 0 deletions src/Framework/ProjectEvaluationStartedEventArgs.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -30,5 +30,10 @@ public ProjectEvaluationStartedEventArgs(string? message, params object[]? messa
/// Gets or sets the full path of the project that started evaluation.
/// </summary>
public string? ProjectFile { get; set; }

/// <summary>
/// Gets or sets is the project is currently on restore phase.
/// </summary>
public bool IsRestore { get; internal set; }
maridematte marked this conversation as resolved.
Show resolved Hide resolved
Copy link
Member

Choose a reason for hiding this comment

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

I think it's worth considering keeping the property internal for now. It's needed only internally for the infra. For a public API I wonder if exposing all global build properties wouldn't be potentially more useful. But since it's generally hard to remove or update an API once shipped, I think I would vote for not exposing anything publicly for now.

Copy link
Member

Choose a reason for hiding this comment

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

Actually - assuming that we also want to use this flag when replaying a binlog, we need to make a public surface change anyway. In other words, the new flag should likely be serialized. cc @JanKrivanek to confirm.

Copy link
Member

Choose a reason for hiding this comment

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

That's correct.
BuildEventArgsWritter (and BuildEventArgsReader) need to be adjusted accordingly, plus the BinLogger version needs to be incremented

msbuild/src/Build/Logging/BinaryLogger/BinaryLogger.cs

Line 81 in a8e224f

internal const int FileFormatVersion = 20;
.
Then we'll need to copy the identical change to the https://github.com/KirillOsenkov/MSBuildStructuredLog/blob/main/src/StructuredLogger/BinaryLogger/BuildEventArgsReader.cs (and preferrably BuildEventArgsWritter as well) - so that viewer is fine with the change (it'd grace handle skip the extra field, but would report it as unknown change).

The analogous change seem to have been forgotten for tracing: #10016 (comment), so alternatively we can have bothe of those changes be reflected in a single PR with single BinaryLogger version bump.

Copy link
Member

@JanKrivanek JanKrivanek May 13, 2024 •
edited
Loading

Choose a reason for hiding this comment

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

FYI @KirillOsenkov (just a heads up that same small changes will be comming. We should handle them proactively ourselves)

Copy link
Member

Choose a reason for hiding this comment

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

Perhaps @JanKrivanek we should have a wiki page somewhere with a walkthrough of how to do BinaryLogger related changes? Including the viewer PR, version increments etc. Feel free to add to the wiki on the viewer repo or here, wherever it makes more sense for the team.

Copy link
Member

Choose a reason for hiding this comment

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

Good idea - I'll find a time to do this

}
}
Loading