This PR is not intended to be merged, it was created to review changes made to help debugging the plug-in

src/Common.Tests/PluginSettingsTests.cs

@@ -351,16 +351,20 @@ public void GlobalPropertiesToIgnoreSetting(string? settingValue, string[] expec
         CollectionAssert.AreEqual(expectedValue, pluginSettings.GlobalPropertiesToIgnore.ToList());
     }
 
+    [TestMethod]
+    public void GetResultsForUnqueriedDependenciesSetting()
+        => TestBoolSetting(nameof(PluginSettings.GetResultsForUnqueriedDependencies), pluginSettings => pluginSettings.GetResultsForUnqueriedDependencies);
+
     private static void TestBoolSetting(string settingName, Func<PluginSettings, bool> valueAccessor)
         => TestBasicSetting(
             settingName,
             valueAccessor,
-            testValues: new[] { false, true });
+            testValues: [false, true]);
 
     private static void TestBasicSetting<T>(
         string settingName,
         Func<PluginSettings, T> valueAccessor,
-        T[] testValues)
+        ReadOnlySpan<T> testValues)
     {
         T defaultValue = valueAccessor(DefaultPluginSettings);
 

src/Common/Caching/CacheClient.cs

@@ -385,6 +385,7 @@ await AddNodeAsync(
         if (!selector.HasValue)
         {
             // GetMatchingSelectorAsync logs sufficiently
+            MSBuildCachePluginBase.DumpPartialFingerprintLog("weak", nodeContext, weakFingerprint);
             return (null, null);
         }
 

src/Common/Fingerprinting/FingerprintFactory.cs

@@ -96,7 +96,7 @@ void AddSettingToFingerprint(IReadOnlyCollection<Glob>? patterns, string setting
                 string vcToolsVersion = nodeContext.ProjectInstance.GetPropertyValue("VCToolsVersion");
                 if (!string.IsNullOrEmpty(vcToolsVersion))
                 {
-                    entries.Add(CreateFingerprintEntry($"VCToolsVersion: {vcToolsVersion}"));
+                    //entries.Add(CreateFingerprintEntry($"VCToolsVersion: {vcToolsVersion}"));
                 }
 
                 // If the .NET SDK changes, the node should rebuild.

src/Common/MSBuildCachePluginBase.cs

@@ -67,6 +67,7 @@ public abstract class MSBuildCachePluginBase<TPluginSettings> : ProjectCachePlug
     private DirectoryLock? _localCacheDirectoryLock;
     private SemaphoreSlim? _singlePluginInstanceMutex;
     private PathNormalizer? _pathNormalizer;
+    private Func<NodeContext, PluginLoggerBase, CancellationToken, Task<CacheResult>>? _getCacheResultAsync;
 
     private int _cacheHitCount;
     private long _cacheHitDurationMilliseconds;
@@ -122,7 +123,8 @@ static MSBuildCachePluginBase() =>
         nameof(_fileAccessRepository),
         nameof(_cacheClient),
         nameof(_ignoredOutputPatterns),
-        nameof(_identicalDuplicateOutputPatterns)
+        nameof(_identicalDuplicateOutputPatterns),
+        nameof(_getCacheResultAsync)
     )]
     protected bool Initialized { get; private set; }
 
@@ -321,6 +323,16 @@ private async Task BeginBuildInnerAsync(CacheContext context, PluginLoggerBase l
         _fileAccessRepository = new FileAccessRepository(logger, Settings);
         _cacheClient = await CreateCacheClientAsync(logger, cancellationToken);
 
+        if (Settings.GetResultsForUnqueriedDependencies)
+        {
+            ConcurrentDictionary<NodeContext, Lazy<Task<CacheResult>>> cacheResults = new(concurrencyLevel: Environment.ProcessorCount, _nodeContexts.Count);
+            _getCacheResultAsync = (nodeContext, logger, cancellationToken) => GetCacheResultRecursivelyAsync(cacheResults, nodeContext, logger, cancellationToken);
+        }
+        else
+        {
+            _getCacheResultAsync = GetCacheResultNonRecursiveAsync;
+        }
+
         // Ensure all logs are written
         await Task.WhenAll(dumpParserInfoTasks);
         await dumpNodeContextsTask;
@@ -356,6 +368,7 @@ private async Task<CacheResult> GetCacheResultInnerAsync(BuildRequestData buildR
         if (!Initialized)
         {
             // BeginBuild didn't finish successfully. It's expected to log sufficiently, so just bail.
+            logger.LogWarning($"Cache Miss for build {buildRequest.ProjectFullPath}: cache is not initialized.");
             return CacheResult.IndicateNonCacheHit(CacheResultType.CacheNotApplicable);
         }
 
@@ -369,20 +382,87 @@ private async Task<CacheResult> GetCacheResultInnerAsync(BuildRequestData buildR
         NodeDescriptor nodeDescriptor = _nodeDescriptorFactory.Create(projectInstance);
         if (!_nodeContexts.TryGetValue(nodeDescriptor, out NodeContext? nodeContext))
         {
+            logger.LogWarning($"Cache Miss for build {buildRequest.ProjectFullPath}: cannot find node context {nodeDescriptor}");
             return CacheResult.IndicateNonCacheHit(CacheResultType.CacheNotApplicable);
         }
 
         nodeContext.SetStartTime();
 
-        if (!nodeContext.TargetNames.SetEquals(buildRequest.TargetNames))
+        if (!nodeContext.TargetNames.IsSupersetOf(buildRequest.TargetNames))
         {
-            logger.LogMessage($"`TargetNames` does not match for {nodeContext.Id}. `{string.Join(";", nodeContext.TargetNames)}` vs `{string.Join(";", buildRequest.TargetNames)}`.");
+            logger.LogWarning($"Cache Miss for build {buildRequest.ProjectFullPath}: `TargetNames` does not match for {nodeContext.Id}. `{string.Join(";", nodeContext.TargetNames)}` vs `{string.Join(";", buildRequest.TargetNames)}`.");
             return CacheResult.IndicateNonCacheHit(CacheResultType.CacheNotApplicable);
         }
 
+        var result = await _getCacheResultAsync(nodeContext, logger, cancellationToken);
+
+        string targets = string.Join(";", buildRequest.TargetNames);
+        logger.LogWarning($"Cache {result.ResultType} for build {buildRequest.ProjectFullPath} ({targets})");
+
+        return result;
+    }
+
+    private async Task<CacheResult> GetCacheResultRecursivelyAsync(
+        ConcurrentDictionary<NodeContext, Lazy<Task<CacheResult>>> cacheResults,
+        NodeContext nodeContext,
+        PluginLoggerBase logger,
+        CancellationToken cancellationToken)
+    {
+        // Ensure we only query a node exactly once. MSBuild won't query a project more than once, but when recursion is enabled,
+        // we might have multiple build requests querying the same unqueried dependency.
+        return await cacheResults.GetOrAdd(nodeContext, new Lazy<Task<CacheResult>>(
+            async () =>
+            {
+                foreach (NodeContext dependency in nodeContext.Dependencies)
+                {
+                    if (dependency.BuildResult == null)
+                    {
+                        logger.LogMessage($"Querying cache for missing build result for dependency '{dependency.Id}'");
+                        CacheResult dependencyResult = await GetCacheResultRecursivelyAsync(cacheResults, dependency, logger, cancellationToken);
+                        logger.LogMessage($"Dependency '{dependency.Id}' cache result: '{dependencyResult.ResultType}'");
+
+                        if (dependencyResult.ResultType != CacheResultType.CacheHit)
+                        {
+                            logger.LogWarning($"Cache miss due to failed build result for dependency '{dependency.Id}'");
+                            Interlocked.Increment(ref _cacheMissCount);
+                            return CacheResult.IndicateNonCacheHit(CacheResultType.CacheMiss);
+                        }
+                    }
+                }
+
+                return await GetCacheResultSingleAsync(nodeContext, logger, cancellationToken);
+            })).Value;
+    }
+
+    private async Task<CacheResult> GetCacheResultNonRecursiveAsync(NodeContext nodeContext, PluginLoggerBase logger, CancellationToken cancellationToken)
+    {
+        foreach (NodeContext dependency in nodeContext.Dependencies)
+        {
+            if (dependency.BuildResult == null)
+            {
+                logger.LogWarning($"Cache miss due to failed or missing build result for dependency '{dependency.Id}'");
+                Interlocked.Increment(ref _cacheMissCount);
+                return CacheResult.IndicateNonCacheHit(CacheResultType.CacheMiss);
+            }
+        }
+
+        return await GetCacheResultSingleAsync(nodeContext, logger, cancellationToken);
+    }
+
+    private async Task<CacheResult> GetCacheResultSingleAsync(NodeContext nodeContext, PluginLoggerBase logger, CancellationToken cancellationToken)
+    {
+        if (!Initialized)
+        {
+            throw new InvalidOperationException();
+        }
+
+        nodeContext.SetStartTime();
+
         (PathSet? pathSet, NodeBuildResult? nodeBuildResult) = await _cacheClient.GetNodeAsync(nodeContext, cancellationToken);
         if (nodeBuildResult is null)
         {
+            logger.LogWarning($"Cache miss due to failed to find build result '{nodeContext.Id}'");
+
             Interlocked.Increment(ref _cacheMissCount);
             return CacheResult.IndicateNonCacheHit(CacheResultType.CacheMiss);
         }
@@ -472,6 +552,7 @@ private async Task HandleProjectFinishedInnerAsync(FileAccessContext fileAccessC
         // If file access reports are disabled in MSBuild we can't cache anything as we don't know what to cache.
         if (!_hasHadFileAccessReport)
         {
+            await DumpFingerprintLogAsync(logger, nodeContext, null);
             return;
         }
 
@@ -798,36 +879,53 @@ private async Task DumpFingerprintLogAsync(
         {
             logger.LogWarning($"Non-fatal exception while writing {filePath}. {ex.GetType().Name}: {ex.Message}");
         }
+    }
 
-        static void WriteFingerprintJson(Utf8JsonWriter jsonWriter, string propertyName, Fingerprint? fingerprint)
+    internal static void DumpPartialFingerprintLog(string fingerprintType, NodeContext nodeContext, Fingerprint fingerprint)
+    {
+        string filePath = Path.Combine(nodeContext.LogDirectory, $"fingerprint_{fingerprintType}.json");
+        try
         {
-            jsonWriter.WritePropertyName(propertyName);
-
-            if (fingerprint == null)
-            {
-                jsonWriter.WriteNullValue();
-                return;
-            }
+            using FileStream fileStream = File.Create(filePath);
+            using var jsonWriter = new Utf8JsonWriter(fileStream, SerializationHelper.WriterOptions);
 
             jsonWriter.WriteStartObject();
+            WriteFingerprintJson(jsonWriter, fingerprintType, fingerprint);
+            jsonWriter.WriteEndObject();
+        }
+        catch (Exception)
+        {
+        }
+    }
 
-            jsonWriter.WriteString("hash", fingerprint.Hash.ToHex());
+    private static void WriteFingerprintJson(Utf8JsonWriter jsonWriter, string propertyName, Fingerprint? fingerprint)
+    {
+        jsonWriter.WritePropertyName(propertyName);
 
-            jsonWriter.WritePropertyName("entries");
-            jsonWriter.WriteStartArray();
+        if (fingerprint == null)
+        {
+            jsonWriter.WriteNullValue();
+            return;
+        }
 
-            foreach (FingerprintEntry entry in fingerprint.Entries)
-            {
-                jsonWriter.WriteStartObject();
-                jsonWriter.WriteString("hash", entry.Hash.ToHex());
-                jsonWriter.WriteString("description", entry.Description);
-                jsonWriter.WriteEndObject();
-            }
+        jsonWriter.WriteStartObject();
+
+        jsonWriter.WriteString("hash", fingerprint.Hash.ToHex());
 
-            jsonWriter.WriteEndArray(); // entries array
+        jsonWriter.WritePropertyName("entries");
+        jsonWriter.WriteStartArray();
 
+        foreach (FingerprintEntry entry in fingerprint.Entries)
+        {
+            jsonWriter.WriteStartObject();
+            jsonWriter.WriteString("hash", entry.Hash.ToHex());
+            jsonWriter.WriteString("description", entry.Description);
             jsonWriter.WriteEndObject();
         }
+
+        jsonWriter.WriteEndArray(); // entries array
+
+        jsonWriter.WriteEndObject();
     }
 
     private static async Task DumpBuildResultLogAsync(

src/Common/NodeDescriptor.cs

@@ -3,9 +3,11 @@
 
 using System;
 using System.Collections.Generic;
+using System.Diagnostics;
 
 namespace Microsoft.MSBuildCache;
 
+[DebuggerDisplay($"{{{nameof(DebuggerDisplay)}, nq}}")]
 internal readonly struct NodeDescriptor : IEquatable<NodeDescriptor>
 {
     private readonly string _projectFullPath;
@@ -23,6 +25,8 @@ public NodeDescriptor(string projectFullPath, SortedDictionary<string, string> f
     /// </summary>
     public IReadOnlyDictionary<string, string> FilteredGlobalProperties => _filteredGlobalProperties;
 
+    private string DebuggerDisplay => $"{_projectFullPath} ({_filteredGlobalProperties.Count})";
+
     public bool Equals(NodeDescriptor other)
     {
         if (!_projectFullPath.Equals(other._projectFullPath, StringComparison.OrdinalIgnoreCase))

src/Common/PluginSettings.cs

@@ -101,6 +101,8 @@ public string LocalCacheRootPath
 
     public IReadOnlyList<string> GlobalPropertiesToIgnore { get; init; } = Array.Empty<string>();
 
+    public bool GetResultsForUnqueriedDependencies { get; init; }
+
     public static T Create<T>(
         IReadOnlyDictionary<string, string> settings,
         PluginLoggerBase logger,

src/Common/build/Microsoft.MSBuildCache.Common.targets

@@ -20,6 +20,17 @@
     <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);MSBuildCacheAllowFileAccessAfterProjectFinishFilePatterns</MSBuildCacheGlobalPropertiesToIgnore>
     <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);MSBuildCacheAllowProcessCloseAfterProjectFinishProcessPatterns</MSBuildCacheGlobalPropertiesToIgnore>
     <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);MSBuildCacheGlobalPropertiesToIgnore</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);MSBuildCachePackageName</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);MSBuildCachePackageVersion</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);IsGraphBuild</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);UseHostCompilerIfAvailable</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);LangID</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);LangName</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);DefineExplicitDefaults</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);EnableCaching</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);VSIDEResolvedNonMSBuildProjectOutputs</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);DevEnvDir</MSBuildCacheGlobalPropertiesToIgnore>
+    <MSBuildCacheGlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore);MSBuildCacheGetResultsForUnqueriedDependencies</MSBuildCacheGlobalPropertiesToIgnore>
   </PropertyGroup>
 
   <ItemGroup Condition="'$(MSBuildCacheEnabled)' != 'false'">
@@ -39,6 +50,7 @@
       <AllowFileAccessAfterProjectFinishFilePatterns>$(MSBuildCacheAllowFileAccessAfterProjectFinishFilePatterns)</AllowFileAccessAfterProjectFinishFilePatterns>
       <AllowProcessCloseAfterProjectFinishProcessPatterns>$(MSBuildCacheAllowProcessCloseAfterProjectFinishProcessPatterns)</AllowProcessCloseAfterProjectFinishProcessPatterns>
       <GlobalPropertiesToIgnore>$(MSBuildCacheGlobalPropertiesToIgnore)</GlobalPropertiesToIgnore>
+      <GetResultsForUnqueriedDependencies>$(MSBuildCacheGetResultsForUnqueriedDependencies)</GetResultsForUnqueriedDependencies>
     </ProjectCachePlugin>
   </ItemGroup>