Schedule proxy builds to inproc node

src/Build.UnitTests/BackEnd/Scheduler_Tests.cs

@@ -10,6 +10,8 @@
 using Microsoft.Build.Shared;
 using Microsoft.Build.Execution;
 using Microsoft.Build.Evaluation;
+using Microsoft.Build.Experimental.ProjectCache;
+using Shouldly;
 using TaskItem = Microsoft.Build.Execution.ProjectItemInstance.TaskItem;
 using Xunit;
 
@@ -520,6 +522,31 @@ public void TestTraversalAffinityIsInProc()
             Assert.Equal(request1, response[0].BuildRequest);
         }
 
+        /// <summary>
+        /// Make sure that traversal projects are marked with an affinity of "InProc", which means that
+        /// even if multiple are available, we should still only have the single inproc node.
+        /// </summary>
+        [Fact]
+        public void TestProxyAffinityIsInProc()
+        {
+            _host.BuildParameters.MaxNodeCount = 4;
+            ReportDefaultParentRequestIsFinished();
+
+            CreateConfiguration(1, "foo.csproj");
+
+            BuildRequest request1 = CreateProxyBuildRequest(1, 1, new ProxyTargets(new Dictionary<string, string> {{"foo", "bar"}}), null);
+
+            BuildRequestBlocker blocker = new BuildRequestBlocker(-1, new string[] { }, new[] { request1 });
+            List<ScheduleResponse> response = new List<ScheduleResponse>(_scheduler.ReportRequestBlocked(1, blocker));
+
+            // There will be no request to create a new node, because both of the above requests are proxy build requests,
+            // which have an affinity of "inproc", and the inproc node already exists.
+            Assert.Single(response);
+            Assert.Equal(ScheduleActionType.ScheduleWithConfiguration, response[0].Action);
+            Assert.Equal(request1, response[0].BuildRequest);
+            Assert.Equal(Scheduler.InProcNodeId, response[0].NodeId);
+        }
+
         /// <summary>
         /// With something approximating the BuildManager's build loop, make sure that we don't end up
         /// trying to create more nodes than we can actually support.
@@ -729,8 +756,10 @@ private BuildRequest CreateBuildRequest(int nodeRequestId, int configId, string[
         /// <summary>
         /// Creates a build request.
         /// </summary>
-        private BuildRequest CreateBuildRequest(int nodeRequestId, int configId, string[] targets, NodeAffinity nodeAffinity, BuildRequest parentRequest)
+        private BuildRequest CreateBuildRequest(int nodeRequestId, int configId, string[] targets, NodeAffinity nodeAffinity, BuildRequest parentRequest, ProxyTargets proxyTargets = null)
         {
+            (targets == null ^ proxyTargets == null).ShouldBeTrue();
+
             HostServices hostServices = null;
 
             if (nodeAffinity != NodeAffinity.Any)
@@ -739,8 +768,36 @@ private BuildRequest CreateBuildRequest(int nodeRequestId, int configId, string[
                 hostServices.SetNodeAffinity(String.Empty, nodeAffinity);
             }
 
-            BuildRequest request = new BuildRequest(1 /* submissionId */, nodeRequestId, configId, targets, hostServices, BuildEventContext.Invalid, parentRequest);
-            return request;
+            if (targets != null)
+            {
+                return new BuildRequest(
+                    submissionId: 1,
+                    nodeRequestId,
+                    configId,
+                    targets,
+                    hostServices,
+                    BuildEventContext.Invalid,
+                    parentRequest);
+            }
+
+            parentRequest.ShouldBeNull();
+            return new BuildRequest(
+                submissionId: 1,
+                nodeRequestId,
+                configId,
+                proxyTargets,
+                hostServices);
+        }
+
+        private BuildRequest CreateProxyBuildRequest(int nodeRequestId, int configId, ProxyTargets proxyTargets, BuildRequest parentRequest)
+        {
+            return CreateBuildRequest(
+                nodeRequestId,
+                configId,
+                null,
+                NodeAffinity.Any,
+                parentRequest,
+                proxyTargets);
         }
 
         /// <summary>
@@ -778,5 +835,11 @@ private void MockPerformSchedulingActions(IEnumerable<ScheduleResponse> response
                 MockPerformSchedulingActions(moreResponses, ref nodeId, ref inProcNodeExists);
             }
         }
+
+        private void ReportDefaultParentRequestIsFinished()
+        {
+            var buildResult = new BuildResult(_defaultParentRequest);
+            _scheduler.ReportResult(_defaultParentRequest.NodeRequestId, buildResult);
+        }
     }
 }

src/Build.UnitTests/ProjectCache/ProjectCacheTests.cs

@@ -398,6 +398,15 @@ public void ProjectCacheByBuildParametersAndGraphBuildWorks(GraphCacheResponse t
 
             var graphResult = buildSession.BuildGraph(graph);
 
+            if (buildParameters.DisableInProcNode
+                && testData.NonCacheMissResults.Any(c => c.Value.ProxyTargets is not null))
+            {
+                // TODO: remove this branch when the DisableInProcNode failure is fixed by https://github.com/dotnet/msbuild/pull/6400
+                graphResult.OverallResult.ShouldBe(BuildResultCode.Failure);
+                buildSession.Logger.Errors.First().Code.ShouldBe("MSB4223");
+                return;
+            }
+
             graphResult.OverallResult.ShouldBe(BuildResultCode.Success);
 
             buildSession.Dispose();
@@ -425,6 +434,17 @@ public void ProjectCacheByBuildParametersAndBottomUpBuildWorks(GraphCacheRespons
             foreach (var node in graph.ProjectNodesTopologicallySorted)
             {
                 var buildResult = buildSession.BuildProjectFile(node.ProjectInstance.FullPath);
+
+                if (buildParameters.DisableInProcNode &&
+                    testData.NonCacheMissResults.TryGetValue(GetProjectNumber(node), out var cacheResult) &&
+                    cacheResult.ProxyTargets is not null)
+                {
+                    // TODO: remove this branch when the DisableInProcNode failure is fixed by https://github.com/dotnet/msbuild/pull/6400
+                    buildResult.OverallResult.ShouldBe(BuildResultCode.Failure);
+                    buildSession.Logger.Errors.First().Code.ShouldBe("MSB4223");
+                    return;
+                }
+
                 buildResult.OverallResult.ShouldBe(BuildResultCode.Success);
 
                 nodesToBuildResults[node] = buildResult;
@@ -484,6 +504,65 @@ public void ProjectCacheByVSWorkaroundWorks(GraphCacheResponse testData, BuildPa
             }
         }
 
+        [Theory]
+        [InlineData(true)]
+        [InlineData(false)]
+        public void RunningProxyBuildsOnOutOfProcNodesShouldIssueWarning(bool disableInprocNodeViaEnvironmentVariable)
+        {
+            var testData = new GraphCacheResponse(
+                new Dictionary<int, int[]>
+                {
+                    {1, new[] {2}}
+                },
+                new Dictionary<int, CacheResult>
+                {
+                    {1, GraphCacheResponse.SuccessfulProxyTargetResult()},
+                    {2, GraphCacheResponse.SuccessfulProxyTargetResult()}
+                });
+
+            var graph = testData.CreateGraph(_env);
+            var mockCache = new InstanceMockCache(testData);
+
+            var buildParameters = new BuildParameters
+            {
+                MaxNodeCount = Environment.ProcessorCount,
+                ProjectCacheDescriptor = ProjectCacheDescriptor.FromInstance(
+                    mockCache,
+                    null,
+                    graph)
+            };
+
+            if (disableInprocNodeViaEnvironmentVariable)
+            {
+                _env.SetEnvironmentVariable("MSBUILDNOINPROCNODE", "1");
+            }
+            else
+            {
+                buildParameters.DisableInProcNode = true;
+            }
+
+            using var buildSession = new Helpers.BuildManagerSession(_env, buildParameters);
+
+            var graphResult = buildSession.BuildGraph(graph);
+
+            if (!disableInprocNodeViaEnvironmentVariable)
+            {
+                // TODO: remove this branch when the DisableInProcNode failure is fixed by https://github.com/dotnet/msbuild/pull/6400
+                graphResult.OverallResult.ShouldBe(BuildResultCode.Failure);
+                buildSession.Logger.Errors.First().Code.ShouldBe("MSB4223");
+                return;
+            }
+
+            graphResult.OverallResult.ShouldBe(BuildResultCode.Success);
+
+            buildSession.Dispose();
+
+            buildSession.Logger.FullLog.ShouldContain("Static graph based");
+
+            buildSession.Logger.AssertMessageCount("MSB4274", 1);
+
+        }
+
         private void AssertCacheBuild(
             ProjectGraph graph,
             GraphCacheResponse testData,

src/Build/BackEnd/Components/Logging/LoggingContext.cs

@@ -213,6 +213,12 @@ internal void LogFatalError(Exception exception, BuildEventFileInfo file, string
             _hasLoggedErrors = true;
         }
 
+        internal void LogWarning(string messageResourceName, params object[] messageArgs)
+        {
+            ErrorUtilities.VerifyThrow(_isValid, "must be valid");
+            _loggingService.LogWarning(_eventContext, null, BuildEventFileInfo.Empty, messageResourceName, messageArgs);
+        }
+
         /// <summary>
         /// Log a warning
         /// </summary>

src/Build/BackEnd/Components/Scheduler/Scheduler.cs

@@ -11,6 +11,7 @@
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.Build.Execution;
+using Microsoft.Build.Experimental.ProjectCache;
 using Microsoft.Build.Framework;
 using Microsoft.Build.Shared;
 
@@ -166,6 +167,10 @@ internal class Scheduler : IScheduler
         /// </summary>
         private AssignUnscheduledRequestsDelegate _customRequestSchedulingAlgorithm;
 
+        private NodeLoggingContext _inprocNodeContext;
+
+        private int _loggedWarningsForProxyBuildsOnOutOfProcNodes = 0;
+
         /// <summary>
         /// Constructor.
         /// </summary>
@@ -610,6 +615,7 @@ public void InitializeComponent(IBuildComponentHost host)
             _componentHost = host;
             _resultsCache = (IResultsCache)_componentHost.GetComponent(BuildComponentType.ResultsCache);
             _configCache = (IConfigCache)_componentHost.GetComponent(BuildComponentType.ConfigCache);
+            _inprocNodeContext =  new NodeLoggingContext(_componentHost.LoggingService, InProcNodeId, true);
         }
 
         /// <summary>
@@ -791,6 +797,9 @@ private void AssignUnscheduledRequestsToNodes(List<ScheduleResponse> responses,
                 {
                     // We want to find more work first, and we assign traversals to the in-proc node first, if possible.
                     AssignUnscheduledRequestsByTraversalsFirst(responses, idleNodes);
+
+                    AssignUnscheduledProxyBuildRequestsToInProcNode(responses, idleNodes);
+
                     if (idleNodes.Count == 0)
                     {
                         return;
@@ -972,6 +981,29 @@ private void AssignUnscheduledRequestsByTraversalsFirst(List<ScheduleResponse> r
             }
         }
 
+        /// <summary>
+        /// Proxy build requests <see cref="ProxyTargets"/> should be really cheap (only return properties and items) and it's not worth
+        /// paying the IPC cost and re-evaluating them on out of proc nodes (they are guaranteed to be evaluated in the Scheduler process).
+        /// </summary>
+        private void AssignUnscheduledProxyBuildRequestsToInProcNode(List<ScheduleResponse> responses, HashSet<int> idleNodes)
+        {
+            if (idleNodes.Contains(InProcNodeId))
+            {
+                List<SchedulableRequest> unscheduledRequests = new List<SchedulableRequest>(_schedulingData.UnscheduledRequestsWhichCanBeScheduled);
+                foreach (SchedulableRequest request in unscheduledRequests)
+                {
+                    if (CanScheduleRequestToNode(request, InProcNodeId) && IsProxyBuildRequest(request.BuildRequest))
+                    {
+                        {
+                            AssignUnscheduledRequestToNode(request, InProcNodeId, responses);
+                            idleNodes.Remove(InProcNodeId);
+                            break;
+                        }
+                    }
+                }
+            }
+        }
+
         /// <summary>
         /// Returns true if the request is for a traversal project.  Traversals are used to find more work.
         /// </summary>
@@ -980,6 +1012,11 @@ private bool IsTraversalRequest(BuildRequest request)
             return _configCache[request.ConfigurationId].IsTraversal;
         }
 
+        private bool IsProxyBuildRequest(BuildRequest request)
+        {
+            return request.ProxyTargets != null;
+        }
+
         /// <summary>
         /// Assigns requests to nodes attempting to ensure each node has the same number of configurations assigned to it.
         /// </summary>
@@ -1348,7 +1385,27 @@ private void AssignUnscheduledRequestToNode(SchedulableRequest request, int node
 
             responses.Add(ScheduleResponse.CreateScheduleResponse(nodeId, request.BuildRequest, mustSendConfigurationToNode));
             TraceScheduler("Executing request {0} on node {1} with parent {2}", request.BuildRequest.GlobalRequestId, nodeId, (request.Parent == null) ? -1 : request.Parent.BuildRequest.GlobalRequestId);
+
+            WarnWhenProxyBuildsGetScheduledOnOutOfProcNode();
+
             request.ResumeExecution(nodeId);
+
+            void WarnWhenProxyBuildsGetScheduledOnOutOfProcNode()
+            {
+                if (request.BuildRequest.ProxyTargets != null && nodeId != InProcNodeId)
+                {
+                    ErrorUtilities.VerifyThrow(
+                        _componentHost.BuildParameters.DisableInProcNode || _forceAffinityOutOfProc,
+                        "Proxy requests should only get scheduled to out of proc nodes when the inproc node is disabled");
+
+                    var loggedWarnings = Interlocked.CompareExchange(ref _loggedWarningsForProxyBuildsOnOutOfProcNodes, 1, 0);
+
+                    if (loggedWarnings == 0)
+                    {
+                        _inprocNodeContext.LogWarning("ProxyRequestNotScheduledOnInprocNode");
+                    }
+                }
+            }
         }
 
         /// <summary>
@@ -2057,6 +2114,11 @@ private NodeAffinity GetNodeAffinityForRequest(BuildRequest request)
                 return NodeAffinity.InProc;
             }
 
+            if (IsProxyBuildRequest(request))
+            {
+                return NodeAffinity.InProc;
+            }
+
             BuildRequestConfiguration configuration = _configCache[request.ConfigurationId];
 
             // The affinity may have been specified by the host services.

src/Build/Resources/Strings.resx

@@ -1894,4 +1894,7 @@ Utilization:          {0} Average Utilization: {1:###.0}</value>
   <data name="KillingProcessWithPid" xml:space="preserve">
     <value>Killing process with pid = {0}.</value>
   </data>
+  <data name="ProxyRequestNotScheduledOnInprocNode" xml:space="preserve">
+    <value>MSB4274: Disabling the inproc node leads to performance degradation when using project cache plugins that emit proxy build requests.</value>
+  </data>
 </root>