Skip to content
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
85 changes: 85 additions & 0 deletions src/Build.UnitTests/BackEnd/BuildManager_Tests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -4622,5 +4622,90 @@ public void MultiThreadedBuild_SharedConfiguration_DoesNotCrash()
_logger.AssertLogContains($"Child{i} built");
}
}

/// <summary>
/// Regression test: when MSBUILDDEBUGSCHEDULER is enabled in multithreaded (-mt) mode,
/// multiple in-proc node engines write trace output to the same EngineTrace_{PID}.txt file.
/// Previously, each engine used lock(this) which only serialized within one instance,
/// allowing concurrent FileStream opens with FileShare.Read. The IOException fatally crashed
/// the ActionBlock work queue, silently dropping subsequent request completions and causing
/// a deadlock.
///
/// The fix uses a static lock across all engine instances so a single trace file is safe,
/// and catches non-critical exceptions so trace failures can never crash the build engine.
/// </summary>
[Fact(Timeout = 30_000)]
public async System.Threading.Tasks.Task MultiThreadedBuild_WithDebugSchedulerTracing_DoesNotDeadlock()
{
await System.Threading.Tasks.Task.Run(() =>
{
string debugPath = _env.CreateFolder().Path;
_env.SetEnvironmentVariable("MSBUILDDEBUGSCHEDULER", "1");
_env.SetEnvironmentVariable("MSBUILDDEBUGPATH", debugPath);
FrameworkDebugUtils.SetDebugPath();

// Create a root project that builds several independent child projects in parallel.
// This forces multiple in-proc nodes to run concurrently, which triggers
// concurrent TraceEngine() calls.
const int childCount = 4;
string[] childPaths = new string[childCount];

string childContent = CleanupFileContents("""
<Project ToolsVersion=`msbuilddefaulttoolsversion`>
<Target Name="Build">
<Message Text="Child built" Importance="High" />
</Target>
</Project>
""");

for (int i = 0; i < childCount; i++)
{
childPaths[i] = _env.CreateFile(".proj").Path;
File.WriteAllText(childPaths[i], childContent);
}

string rootContent = CleanupFileContents($"""
<Project ToolsVersion=`msbuilddefaulttoolsversion`>
<Target Name="Build">
<MSBuild Projects="{string.Join(";", childPaths)}" BuildInParallel="true" />
<Message Text="Root completed" Importance="High" />
</Target>
</Project>
""");

string rootPath = _env.CreateFile(".proj").Path;
File.WriteAllText(rootPath, rootContent);

var buildParameters = new BuildParameters
{
MaxNodeCount = childCount + 1,
EnableNodeReuse = false,
MultiThreaded = true,
DisableInProcNode = false,
SaveOperatingEnvironment = false,
Loggers = [_logger],
};

var data = new BuildRequestData(rootPath, new Dictionary<string, string>(), null,
["Build"], null);

BuildManager.DefaultBuildManager.Dispose();
BuildResult result = BuildManager.DefaultBuildManager.Build(buildParameters, data);

result.OverallResult.ShouldBe(BuildResultCode.Success);
_logger.AssertLogContains("Root completed");

// Verify that scheduler tracing actually produced at least one non-empty trace file
// in the configured debug directory.
string[] traceFiles = Directory.GetFiles(debugPath, "EngineTrace_*.txt");
traceFiles.ShouldNotBeEmpty("Expected at least one EngineTrace_*.txt file to be created in the debug directory.");

bool hasNonEmptyTraceFile = traceFiles
.Select(path => new FileInfo(path))
.Any(info => info.Length > 0);

hasNonEmptyTraceFile.ShouldBeTrue("Expected at least one EngineTrace_*.txt file to contain trace data.");
});
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,12 @@ namespace Microsoft.Build.BackEnd
/// </remarks>
internal class BuildRequestEngine : IBuildRequestEngine, IBuildComponent
{
/// <summary>
/// Static lock serializing trace file writes across all BuildRequestEngine instances.
/// In multithreaded (-mt) mode, multiple engines share the same process and trace file.
/// </summary>
private static readonly object s_traceLock = new();

/// <summary>
/// The starting unresolved configuration id assigned by the engine.
/// </summary>
Expand Down Expand Up @@ -1559,15 +1565,24 @@ private void TraceEngine(string format, params object[] stuff)
{
if (_debugDumpState)
{
lock (this)
lock (s_traceLock)
{
FileUtilities.EnsureDirectoryExists(_debugDumpPath);
try
{
FileUtilities.EnsureDirectoryExists(_debugDumpPath);

using (StreamWriter file = FileUtilities.OpenWrite(string.Format(CultureInfo.CurrentCulture, Path.Combine(_debugDumpPath, @"EngineTrace_{0}.txt"), EnvironmentUtilities.CurrentProcessId), append: true))
using (StreamWriter file = FileUtilities.OpenWrite(string.Format(CultureInfo.CurrentCulture, Path.Combine(_debugDumpPath, @"EngineTrace_{0}.txt"), EnvironmentUtilities.CurrentProcessId), append: true))
{
string message = String.Format(CultureInfo.CurrentCulture, format, stuff);
file.WriteLine("{0}({1})-{2}: {3}", Thread.CurrentThread.Name, Environment.CurrentManagedThreadId, DateTime.UtcNow.Ticks, message);
file.Flush();
}
}
catch (Exception e) when (!ExceptionHandling.IsCriticalException(e))
{
string message = String.Format(CultureInfo.CurrentCulture, format, stuff);
file.WriteLine("{0}({1})-{2}: {3}", Thread.CurrentThread.Name, Environment.CurrentManagedThreadId, DateTime.UtcNow.Ticks, message);
file.Flush();
// Trace file failures must never crash the build engine.
Comment thread
AR-May marked this conversation as resolved.
// Matches the defensive pattern used by Scheduler.TraceScheduler.
_nodeLoggingContext?.LogCommentFromText(MessageImportance.Low, $"Failed to write to engine trace file: {e}");
}
}
}
Expand Down
Loading