Ensure context is not cached before logging info (#6437)

Fixes #6436 which causes this crash in cases where MSBuild's result
caching is turned on (generally this is for large builds in 32-bit
MSBuild).

```
MSBUILD : error MSB1025: An internal failure occurred while running MSBuild.
Microsoft.Build.Shared.InternalErrorException: MSB0001: Internal MSBuild Error: We shouldn't be accessing the ProjectInstance when the configuration is cached.
   at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Exception innerException, Object[] args)
   at Microsoft.Build.BackEnd.BuildRequestConfiguration.get_Project()
   at Microsoft.Build.BackEnd.Logging.NodeLoggingContext.LogProjectStarted(BuildRequest request, BuildRequestConfiguration configuration)
   at Microsoft.Build.BackEnd.Logging.NodeLoggingContext.LogRequestHandledFromCache(BuildRequest request, BuildRequestConfiguration configuration, BuildResult result)
   at Microsoft.Build.BackEnd.Scheduler.LogRequestHandledFromCache(BuildRequest request, BuildResult result)
   at Microsoft.Build.BackEnd.Scheduler.HandleRequestBlockedByNewRequests(SchedulableRequest parentRequest, BuildRequestBlocker blocker, List`1 responses)
   at Microsoft.Build.BackEnd.Scheduler.ReportRequestBlocked(Int32 nodeId, BuildRequestBlocker blocker)
   at Microsoft.Build.Execution.BuildManager.HandleNewRequest(Int32 node, BuildRequestBlocker blocker)
   at Microsoft.Build.Execution.BuildManager.ProcessPacket(Int32 node, INodePacket packet)
   at Microsoft.Build.Execution.BuildManager.<>c__DisplayClass76_0.<Microsoft.Build.BackEnd.INodePacketHandler.PacketReceived>b__0()
   at Microsoft.Build.Execution.BuildManager.ProcessWorkQueue(Action action)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Build.Execution.BuildManager.EndBuild()
```

Bump version to 16.9.2 because we actually shipped a .1 but branded it .0.

eng/Versions.props

@@ -2,7 +2,7 @@
 <!-- Copyright (c) .NET Foundation and contributors. All rights reserved. Licensed under the MIT license. See License.txt in the project root for full license information. -->
 <Project>
   <PropertyGroup>
-    <VersionPrefix>16.9.0</VersionPrefix><DotNetFinalVersionKind>release</DotNetFinalVersionKind>
+    <VersionPrefix>16.9.2</VersionPrefix><DotNetFinalVersionKind>release</DotNetFinalVersionKind>
     <AssemblyVersion>15.1.0.0</AssemblyVersion>
     <PreReleaseVersionLabel>preview</PreReleaseVersionLabel>
     <DotNetUseShippingVersions>true</DotNetUseShippingVersions>

src/Build.UnitTests/BinaryLogger_Tests.cs

@@ -1,5 +1,13 @@
 using System;
+using System.Collections.Generic;
+
+using Microsoft.Build.Evaluation;
+using Microsoft.Build.Execution;
+using Microsoft.Build.Framework;
 using Microsoft.Build.Logging;
+
+using Shouldly;
+
 using Xunit;
 using Xunit.Abstractions;
 
@@ -92,6 +100,49 @@ public void BinaryLoggerShouldNotThrowWhenMetadataCannotBeExpanded()
             ObjectModelHelpers.BuildProjectExpectSuccess(project, binaryLogger);
         }
 
+        /// <summary>
+        /// Regression test for https://github.com/dotnet/msbuild/issues/6323.
+        /// </summary>
+        /// <remarks>
+        /// This isn't strictly a binlog test, but it fits here because
+        /// all log event types will be used when the binlog is attached.
+        /// </remarks>
+        [Fact]
+        public void MessagesCanBeLoggedWhenProjectsAreCached()
+        {
+            using var env = TestEnvironment.Create();
+
+            env.SetEnvironmentVariable("MSBUILDDEBUGFORCECACHING", "1");
+
+            using var buildManager = new BuildManager();
+
+            var binaryLogger = new BinaryLogger
+            {
+                Parameters = $"LogFile={_logFile}"
+            };
+
+            // To trigger #6323, there must be at least two project instances.
+            var referenceProject = _env.CreateTestProjectWithFiles("reference.proj", @"
+         <Project>
+            <Target Name='Target2'>
+               <Exec Command='echo a'/>
+            </Target>
+         </Project>");
+
+            var entryProject = _env.CreateTestProjectWithFiles("entry.proj", $@"
+         <Project>
+            <Target Name='BuildSelf'>
+               <Message Text='MessageOutputText'/>
+               <MSBuild Projects='{referenceProject.ProjectFile}' Targets='Target2' />
+               <MSBuild Projects='{referenceProject.ProjectFile}' Targets='Target2' /><!-- yes, again. That way it's a cached result -->
+            </Target>
+         </Project>");
+
+            buildManager.Build(new BuildParameters() { Loggers = new ILogger[] { binaryLogger } },
+                new BuildRequestData(entryProject.ProjectFile, new Dictionary<string, string>(), null, new string[] { "BuildSelf" }, null))
+                .OverallResult.ShouldBe(BuildResultCode.Success);
+        }
+
 
         public void Dispose()
         {

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

@@ -69,7 +69,13 @@ internal ProjectLoggingContext LogProjectStarted(BuildRequestEntry requestEntry)
         internal ProjectLoggingContext LogProjectStarted(BuildRequest request, BuildRequestConfiguration configuration)
         {
             ErrorUtilities.VerifyThrow(this.IsValid, "Build not started.");
-            return new ProjectLoggingContext(this, request, configuration.ProjectFullPath, configuration.ToolsVersion, request.ParentBuildEventContext, configuration.Project?.EvaluationId ?? BuildEventContext.InvalidEvaluationId);
+
+            // If we can retrieve the evaluationId from the project, do so. Don't if it's not available or
+            // if we'd have to retrieve it from the cache in order to access it.
+            // Order is important here because the Project getter will throw if IsCached.
+            int evaluationId = (configuration != null && !configuration.IsCached && configuration.Project != null) ? configuration.Project.EvaluationId : BuildEventContext.InvalidEvaluationId;
+
+            return new ProjectLoggingContext(this, request, configuration.ProjectFullPath, configuration.ToolsVersion, request.ParentBuildEventContext, evaluationId);
         }
 
         /// <summary>