diff --git a/src/Build/BackEnd/BuildManager/BuildManager.cs b/src/Build/BackEnd/BuildManager/BuildManager.cs index 97c7d449b1f..b977410211b 100644 --- a/src/Build/BackEnd/BuildManager/BuildManager.cs +++ b/src/Build/BackEnd/BuildManager/BuildManager.cs @@ -1038,9 +1038,22 @@ public void EndBuild() } } - _noActiveSubmissionsEvent!.WaitOne(); + { + Stopwatch hangWatch = Stopwatch.StartNew(); + while (!_noActiveSubmissionsEvent!.WaitOne(CrashTelemetryRecorder.EndBuildHangDiagnosticsIntervalMs)) + { + EmitEndBuildHangDiagnostics("WaitingForSubmissions", hangWatch); + } + } + ShutdownConnectedNodes(false /* normal termination */); - _noNodesActiveEvent!.WaitOne(); + { + Stopwatch hangWatch = Stopwatch.StartNew(); + while (!_noNodesActiveEvent!.WaitOne(CrashTelemetryRecorder.EndBuildHangDiagnosticsIntervalMs)) + { + EmitEndBuildHangDiagnostics("WaitingForNodes", hangWatch); + } + } // Wait for all of the actions in the work queue to drain. // _workQueue.Completion.Wait() could throw here if there was an unhandled exception in the work queue, @@ -1230,6 +1243,53 @@ private void RecordCrashTelemetry(Exception exception, bool isUnhandled) host); } + /// + /// Extracts build state under lock and delegates to + /// for EndBuild hang diagnostic telemetry emission. Also writes diagnostics to disk + /// via . + /// + private void EmitEndBuildHangDiagnostics(string waitPhase, Stopwatch hangWatch) + { + int pendingSubmissionCount; + int submissionsWithResultNoLogging = 0; + bool threadExceptionRecorded; + int unmatchedProjectStartedCount; + string? host; + + lock (_syncLock) + { + foreach (BuildSubmissionBase submission in _buildSubmissions.Values) + { + if (submission.BuildResultBase is not null && !submission.LoggingCompleted) + { + submissionsWithResultNoLogging++; + } + } + + pendingSubmissionCount = _buildSubmissions.Count; + threadExceptionRecorded = _threadException is not null; + unmatchedProjectStartedCount = _projectStartedEvents.Count; + host = _buildTelemetry?.BuildEngineHost ?? BuildEnvironmentState.GetHostName(); + } + + string diagnostics = $"Phase={waitPhase}, Duration={hangWatch.ElapsedMilliseconds}ms, " + + $"PendingSubmissions={pendingSubmissionCount}, WithResultNoLogging={submissionsWithResultNoLogging}, " + + $"ThreadException={threadExceptionRecorded}, UnmatchedProjectStarted={unmatchedProjectStartedCount}"; + + ExceptionHandling.DumpHangDiagnosticsToFile(diagnostics); + + CrashTelemetryRecorder.CollectAndEmitEndBuildHangDiagnostics( + waitPhase, + hangWatch.ElapsedMilliseconds, + pendingSubmissionCount, + submissionsWithResultNoLogging, + threadExceptionRecorded, + unmatchedProjectStartedCount, + ProjectCollection.Version?.ToString(), + NativeMethodsShared.FrameworkName, + host); + } + /// /// Convenience method. Submits a lone build request and blocks until results are available. diff --git a/src/Framework.UnitTests/CrashTelemetry_Tests.cs b/src/Framework.UnitTests/CrashTelemetry_Tests.cs index 0e4bd1b8c86..3f003db1625 100644 --- a/src/Framework.UnitTests/CrashTelemetry_Tests.cs +++ b/src/Framework.UnitTests/CrashTelemetry_Tests.cs @@ -341,6 +341,419 @@ public void GetActivityProperties_IncludesNewFields() props[nameof(CrashTelemetry.InnermostExceptionType)].ShouldBe("System.OutOfMemoryException"); } + [Fact] + public void ExtractStackCaller_ReturnsCallerFrame_WhenTopIsThrowHelper() + { + string fakeStack = + " at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Object[] args)\r\n" + + " at Microsoft.Build.BackEnd.RequestBuilder.BuildProject(String projectFile)"; + Exception ex = CreateExceptionWithStack(fakeStack); + + string? caller = CrashTelemetry.ExtractStackCaller(ex); + + caller.ShouldNotBeNull(); + caller.ShouldContain("Microsoft.Build.BackEnd.RequestBuilder.BuildProject"); + } + + [Fact] + public void ExtractStackCaller_ReturnsNull_WhenTopIsNotThrowHelper() + { + string fakeStack = + " at Microsoft.Build.BackEnd.RequestBuilder.BuildProject(String projectFile)\r\n" + + " at Microsoft.Build.BackEnd.BuildManager.Build()"; + Exception ex = CreateExceptionWithStack(fakeStack); + + string? caller = CrashTelemetry.ExtractStackCaller(ex); + + caller.ShouldBeNull(); + } + + [Fact] + public void ExtractStackCaller_ReturnsNull_WhenThrowHelperIsOnlyFrame() + { + string fakeStack = " at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Object[] args)"; + Exception ex = CreateExceptionWithStack(fakeStack); + + string? caller = CrashTelemetry.ExtractStackCaller(ex); + + caller.ShouldBeNull(); + } + + [Fact] + public void ExtractStackCaller_ReturnsNull_WhenNoStackTrace() + { + Exception ex = new Exception("no stack"); + + string? caller = CrashTelemetry.ExtractStackCaller(ex); + + caller.ShouldBeNull(); + } + + [Theory] + [InlineData("ErrorUtilities.VerifyThrowInternalError(")] + [InlineData("ErrorUtilities.ThrowInternalErrorUnreachable(")] + [InlineData("ErrorUtilities.VerifyThrowInternalNull(")] + [InlineData("ErrorUtilities.ThrowInvalidOperation(")] + [InlineData("ErrorUtilities.VerifyThrow(")] + public void ExtractStackCaller_RecognizesAllThrowHelpers(string helperMethod) + { + string fakeStack = + $" at Microsoft.Build.Shared.{helperMethod}String message)\r\n" + + " at Microsoft.Build.Evaluation.Evaluator.Evaluate()"; + Exception ex = CreateExceptionWithStack(fakeStack); + + string? caller = CrashTelemetry.ExtractStackCaller(ex); + + caller.ShouldNotBeNull(); + caller.ShouldContain("Microsoft.Build.Evaluation.Evaluator.Evaluate"); + } + + [Fact] + public void ExtractStackCaller_RedactsFilePaths_InCallerFrame() + { + string fakeStack = + " at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Object[] args)\r\n" + + " at Microsoft.Build.BackEnd.RequestBuilder.BuildProject(String projectFile) in C:\\Users\\username\\src\\file.cs:line 42"; + Exception ex = CreateExceptionWithStack(fakeStack); + + string? caller = CrashTelemetry.ExtractStackCaller(ex); + + caller.ShouldNotBeNull(); + caller.ShouldNotContain("username"); + caller.ShouldContain(""); + caller.ShouldContain(":line 42"); + } + + [Fact] + public void PopulateFromException_SetsStackCaller_WhenThrowHelperIsOnTop() + { + CrashTelemetry telemetry = new(); + + // Simulate a throw-helper scenario using a fake stack trace. + string fakeStack = + " at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Object[] args)\r\n" + + " at Microsoft.Build.Scheduler.ScheduleRequest(BuildRequest request)"; + Exception ex = CreateExceptionWithStack(fakeStack); + + telemetry.PopulateFromException(ex); + + telemetry.StackTop.ShouldNotBeNull(); + telemetry.StackTop!.ShouldContain("ErrorUtilities.ThrowInternalError"); + telemetry.StackCaller.ShouldNotBeNull(); + telemetry.StackCaller!.ShouldContain("Microsoft.Build.Scheduler.ScheduleRequest"); + } + + [Fact] + public void PopulateFromException_SetsExceptionMessage() + { + CrashTelemetry telemetry = new(); + + try + { + throw new InvalidOperationException("something went wrong"); + } + catch (Exception ex) + { + telemetry.PopulateFromException(ex); + } + + telemetry.ExceptionMessage.ShouldBe("something went wrong"); + } + + [Fact] + public void PopulateFromException_StripsInternalErrorPrefix() + { + CrashTelemetry telemetry = new(); + + try + { + throw new Exception("MSB0001: Internal MSBuild Error: All submissions not yet complete."); + } + catch (Exception ex) + { + telemetry.PopulateFromException(ex); + } + + telemetry.ExceptionMessage.ShouldBe("All submissions not yet complete."); + } + + [Fact] + public void TruncateMessage_ReturnsNull_WhenEmpty() + { + CrashTelemetry.TruncateMessage(null).ShouldBeNull(); + CrashTelemetry.TruncateMessage("").ShouldBeNull(); + } + + [Fact] + public void TruncateMessage_TruncatesLongMessages() + { + string longMessage = new string('x', 500); + string? result = CrashTelemetry.TruncateMessage(longMessage); + + result.ShouldNotBeNull(); + result.Length.ShouldBe(256); + } + + [Fact] + public void TruncateMessage_RedactsWindowsPaths() + { + string message = @"C:\Users\johndoe\src\project.csproj unexpectedly not a rooted path"; + string? result = CrashTelemetry.TruncateMessage(message); + + result.ShouldNotBeNull(); + result.ShouldNotContain("johndoe"); + result.ShouldNotContain(@"C:\Users"); + result.ShouldContain(""); + result.ShouldContain("unexpectedly not a rooted path"); + } + + [Fact] + public void TruncateMessage_RedactsUnixPaths() + { + string message = @"/home/johndoe/src/project.csproj unexpectedly not a rooted path"; + string? result = CrashTelemetry.TruncateMessage(message); + + result.ShouldNotBeNull(); + result.ShouldNotContain("johndoe"); + result.ShouldContain(""); + } + + [Fact] + public void TruncateMessage_PreservesNonPathMessages() + { + string message = "All submissions not yet complete."; + string? result = CrashTelemetry.TruncateMessage(message); + result.ShouldBe("All submissions not yet complete."); + } + + [Fact] + public void PopulateFromException_SetsCrashThreadName() + { + CrashTelemetry telemetry = new(); + + try + { + throw new Exception("test"); + } + catch (Exception ex) + { + telemetry.PopulateFromException(ex); + } + + // The thread name may be null in test harness but the property should be set (even if null). + // Just verify no exception was thrown during population. + // In a named-thread scenario, it would capture the name. + } + + [Fact] + public void GetProperties_IncludesStackCaller_WhenSet() + { + CrashTelemetry telemetry = new() + { + ExceptionType = "Microsoft.Build.Framework.InternalErrorException", + IsUnhandled = true, + StackTop = "at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Object[] args)", + StackCaller = "at Microsoft.Build.BackEnd.RequestBuilder.BuildProject(String projectFile)", + ExceptionMessage = "All submissions not yet complete.", + }; + + IDictionary props = telemetry.GetProperties(); + props[nameof(CrashTelemetry.StackCaller)].ShouldBe("at Microsoft.Build.BackEnd.RequestBuilder.BuildProject(String projectFile)"); + props[nameof(CrashTelemetry.ExceptionMessage)].ShouldBe("All submissions not yet complete."); + } + + [Fact] + public void GetProperties_OmitsStackCaller_WhenNull() + { + CrashTelemetry telemetry = new() + { + ExceptionType = "System.NullReferenceException", + IsUnhandled = true, + StackTop = "at Microsoft.Build.BackEnd.RequestBuilder.BuildProject(String projectFile)", + StackCaller = null, + }; + + IDictionary props = telemetry.GetProperties(); + props.ShouldNotContainKey(nameof(CrashTelemetry.StackCaller)); + } + + [Fact] + public void GetActivityProperties_IncludesStackCaller_WhenSet() + { + CrashTelemetry telemetry = new() + { + ExceptionType = "Microsoft.Build.Framework.InternalErrorException", + IsUnhandled = true, + StackTop = "at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Object[] args)", + StackCaller = "at Microsoft.Build.BackEnd.RequestBuilder.BuildProject(String projectFile)", + }; + + Dictionary props = telemetry.GetActivityProperties(); + props[nameof(CrashTelemetry.StackCaller)].ShouldBe("at Microsoft.Build.BackEnd.RequestBuilder.BuildProject(String projectFile)"); + } + + [Fact] + public void PopulateFromException_SetsFullStackTrace() + { + string fakeStack = + " at Microsoft.Build.Shared.ErrorUtilities.ThrowInternalError(String message, Object[] args)\n" + + " at Microsoft.Build.BackEnd.RequestBuilder.BuildProject(String projectFile) in C:\\Users\\user\\src\\file.cs:line 42\n" + + " at Microsoft.Build.BackEnd.BuildManager.Build() in C:\\Users\\user\\src\\mgr.cs:line 100"; + Exception ex = CreateExceptionWithStack(fakeStack); + + CrashTelemetry telemetry = new(); + telemetry.PopulateFromException(ex); + + telemetry.FullStackTrace.ShouldNotBeNull(); + // Should contain all frames + telemetry.FullStackTrace!.ShouldContain("ErrorUtilities.ThrowInternalError"); + telemetry.FullStackTrace.ShouldContain("RequestBuilder.BuildProject"); + telemetry.FullStackTrace.ShouldContain("BuildManager.Build"); + // File paths should be redacted + telemetry.FullStackTrace.ShouldNotContain("C:\\Users\\user"); + telemetry.FullStackTrace.ShouldContain("in :line 42"); + } + + [Fact] + public void ExtractFullStackTrace_ReturnsNull_WhenNoStackTrace() + { + Exception ex = CreateExceptionWithStack(null!); + CrashTelemetry.ExtractFullStackTrace(ex).ShouldBeNull(); + } + + [Fact] + public void ExtractFullStackTrace_TruncatesLongStackTraces() + { + // Build a stack trace longer than MaxStackTraceLength + var sb = new System.Text.StringBuilder(); + for (int i = 0; i < 200; i++) + { + sb.AppendLine($" at Namespace.Type.Method{i}()"); + } + Exception ex = CreateExceptionWithStack(sb.ToString()); + + string? result = CrashTelemetry.ExtractFullStackTrace(ex); + result.ShouldNotBeNull(); + result!.Length.ShouldBeLessThanOrEqualTo(CrashTelemetry.MaxStackTraceLength); + result.ShouldEndWith("... [truncated]"); + } + + [Fact] + public void GetProperties_IncludesFullStackTrace_WhenSet() + { + CrashTelemetry telemetry = new() + { + ExceptionType = "System.Exception", + FullStackTrace = " at Foo.Bar()\n at Baz.Qux()", + }; + + IDictionary props = telemetry.GetProperties(); + props[nameof(CrashTelemetry.FullStackTrace)].ShouldBe(" at Foo.Bar()\n at Baz.Qux()"); + } + + [Fact] + public void SanitizeFilePathsInText_RedactsPathsInStackFrames() + { + string input = " at Foo.Bar() in C:\\Users\\secret\\src\\file.cs:line 99"; + string result = CrashTelemetry.SanitizeFilePathsInText(input); + result.ShouldNotContain("secret"); + result.ShouldContain("in :line 99"); + } + + [Fact] + public void SanitizeFilePathsInText_LeavesNonPathLinesUnchanged() + { + string input = "System.Exception: something broke\n at Foo.Bar()"; + string result = CrashTelemetry.SanitizeFilePathsInText(input); + result.ShouldBe(input); + } + + [Fact] + public void EndBuildHang_GetProperties_IncludesHangDiagnostics() + { + CrashTelemetry telemetry = new() + { + ExitType = CrashExitType.EndBuildHang, + EndBuildWaitPhase = "WaitingForSubmissions", + EndBuildWaitDurationMs = 60000, + PendingSubmissionCount = 3, + SubmissionsWithResultNoLogging = 1, + ThreadExceptionRecorded = false, + UnmatchedProjectStartedCount = 2, + }; + + IDictionary props = telemetry.GetProperties(); + props[nameof(CrashTelemetry.ExitType)].ShouldBe("EndBuildHang"); + props[nameof(CrashTelemetry.EndBuildWaitPhase)].ShouldBe("WaitingForSubmissions"); + props[nameof(CrashTelemetry.EndBuildWaitDurationMs)].ShouldBe("60000"); + props[nameof(CrashTelemetry.PendingSubmissionCount)].ShouldBe("3"); + props[nameof(CrashTelemetry.SubmissionsWithResultNoLogging)].ShouldBe("1"); + props[nameof(CrashTelemetry.ThreadExceptionRecorded)].ShouldBe("False"); + props[nameof(CrashTelemetry.UnmatchedProjectStartedCount)].ShouldBe("2"); + } + + [Fact] + public void EndBuildHang_GetActivityProperties_IncludesHangDiagnostics() + { + CrashTelemetry telemetry = new() + { + ExitType = CrashExitType.EndBuildHang, + EndBuildWaitPhase = "WaitingForNodes", + EndBuildWaitDurationMs = 30000, + PendingSubmissionCount = 0, + SubmissionsWithResultNoLogging = 0, + ThreadExceptionRecorded = true, + UnmatchedProjectStartedCount = 0, + }; + + Dictionary props = telemetry.GetActivityProperties(); + props[nameof(CrashTelemetry.EndBuildWaitPhase)].ShouldBe("WaitingForNodes"); + props[nameof(CrashTelemetry.EndBuildWaitDurationMs)].ShouldBe(30000L); + props[nameof(CrashTelemetry.PendingSubmissionCount)].ShouldBe(0); + props[nameof(CrashTelemetry.SubmissionsWithResultNoLogging)].ShouldBe(0); + props[nameof(CrashTelemetry.ThreadExceptionRecorded)].ShouldBe(true); + props[nameof(CrashTelemetry.UnmatchedProjectStartedCount)].ShouldBe(0); + } + + [Fact] + public void EndBuildHang_GetProperties_OmitsNullHangProperties() + { + CrashTelemetry telemetry = new() + { + ExitType = CrashExitType.EndBuildHang, + EndBuildWaitPhase = "WaitingForSubmissions", + }; + + IDictionary props = telemetry.GetProperties(); + props.ShouldContainKey(nameof(CrashTelemetry.EndBuildWaitPhase)); + props.ShouldNotContainKey(nameof(CrashTelemetry.PendingSubmissionCount)); + props.ShouldNotContainKey(nameof(CrashTelemetry.ThreadExceptionRecorded)); + } + + [Fact] + public void EndBuildHang_DroppedProperties_NotPresent() + { + // Verify that the dropped properties from the critical evaluation + // (ActiveNodeCount, SubmissionsWithNoResult, CancellationRequested, + // ShuttingDown, SchedulerHitNoLoggingCompleted, SchedulerNoLoggingDetails) + // do not appear in the telemetry output. + CrashTelemetry telemetry = new() + { + ExitType = CrashExitType.EndBuildHang, + EndBuildWaitPhase = "WaitingForSubmissions", + EndBuildWaitDurationMs = 30000, + PendingSubmissionCount = 1, + }; + + IDictionary props = telemetry.GetProperties(); + props.ShouldNotContainKey("ActiveNodeCount"); + props.ShouldNotContainKey("SubmissionsWithNoResult"); + props.ShouldNotContainKey("CancellationRequested"); + props.ShouldNotContainKey("ShuttingDown"); + props.ShouldNotContainKey("SchedulerHitNoLoggingCompleted"); + props.ShouldNotContainKey("SchedulerNoLoggingDetails"); + } + /// /// Creates an exception whose StackTrace property returns the given fake stack string. /// diff --git a/src/Framework/Telemetry/CrashTelemetry.cs b/src/Framework/Telemetry/CrashTelemetry.cs index db241340f00..32b8998ed7a 100644 --- a/src/Framework/Telemetry/CrashTelemetry.cs +++ b/src/Framework/Telemetry/CrashTelemetry.cs @@ -84,6 +84,13 @@ internal enum CrashExitType /// An OutOfMemoryException occurred. /// OutOfMemory, + + /// + /// EndBuild is stuck waiting for submissions or nodes to complete. + /// Emitted periodically during the hang so diagnostics are available + /// even if the hang never resolves. + /// + EndBuildHang, } /// @@ -125,9 +132,40 @@ internal class CrashTelemetry : TelemetryBase, IActivityTelemetryDataHolder /// /// The method at the top of the call stack where the exception originated. + /// When the top frame is a known throw-helper (e.g., ErrorUtilities.ThrowInternalError), + /// this still contains that frame for backward compatibility. /// public string? StackTop { get; set; } + /// + /// The first meaningful caller frame, skipping known throw-helper methods. + /// For example, if the top frame is ErrorUtilities.ThrowInternalError, + /// this will contain the frame that called it — which is what you actually need for triage. + /// Null if the stack trace has no frame beyond the throw-helper, or if the top frame + /// is not a throw-helper (in which case already has the meaningful frame). + /// + public string? StackCaller { get; set; } + + /// + /// The full exception stack trace with file paths sanitized to remove PII. + /// Each frame is preserved so that the complete call chain is visible in telemetry, + /// unlike which only captures one frame. + /// Truncated to characters. + /// + public string? FullStackTrace { get; set; } + + /// + /// Maximum number of characters to include from the sanitized stack trace. + /// + internal const int MaxStackTraceLength = 4096; + + /// + /// A prefix of the exception message, truncated and sanitized to avoid PII. + /// Particularly useful for InternalErrorException where the message text + /// identifies the specific assertion that failed. + /// + public string? ExceptionMessage { get; set; } + /// /// The HResult from the exception, if available. /// @@ -181,6 +219,46 @@ internal class CrashTelemetry : TelemetryBase, IActivityTelemetryDataHolder /// public int? MemoryLoadPercent { get; set; } + /// + /// The name of the thread on which the crash occurred. + /// Helps identify whether the crash was on the main thread, a worker thread, + /// a node communication thread, etc. + /// + public string? CrashThreadName { get; set; } + + // --- EndBuild hang diagnostic properties (populated only for ExitType == EndBuildHang) --- + + /// + /// Which wait point EndBuild is stuck at (e.g. "WaitingForSubmissions", "WaitingForNodes"). + /// + public string? EndBuildWaitPhase { get; set; } + + /// + /// How long EndBuild has been waiting, in milliseconds. + /// + public long? EndBuildWaitDurationMs { get; set; } + + /// + /// Number of submissions still in the pending dictionary. + /// + public int? PendingSubmissionCount { get; set; } + + /// + /// Number of submissions that have a BuildResult but LoggingCompleted is false. + /// These submissions are the ones blocking EndBuild. + /// + public int? SubmissionsWithResultNoLogging { get; set; } + + /// + /// Whether a thread exception has been recorded on the BuildManager. + /// + public bool? ThreadExceptionRecorded { get; set; } + + /// + /// Number of unmatched ProjectStarted events (no corresponding ProjectFinished). + /// + public int? UnmatchedProjectStartedCount { get; set; } + /// /// The original exception, kept for passing to FaultEvent. /// Not serialized to telemetry properties. @@ -197,10 +275,14 @@ public void PopulateFromException(Exception exception) InnerExceptionType = exception.InnerException?.GetType().FullName; InnermostExceptionType = GetInnermostException(exception)?.GetType().FullName; HResult = exception.HResult; + ExceptionMessage = TruncateMessage(exception.Message); StackHash = ComputeStackHash(exception); StackTop = ExtractStackTop(exception); + StackCaller = ExtractStackCaller(exception); + FullStackTrace = ExtractFullStackTrace(exception); CrashOriginNamespace = ExtractOriginNamespace(exception); CrashOrigin = ClassifyOrigin(CrashOriginNamespace); + CrashThreadName = System.Threading.Thread.CurrentThread.Name; PopulateMemoryStats(); } @@ -265,6 +347,9 @@ public Dictionary GetActivityProperties() AddIfNotNull(IsUnhandled); AddIfNotNull(StackHash); AddIfNotNull(StackTop); + AddIfNotNull(StackCaller); + AddIfNotNull(FullStackTrace); + AddIfNotNull(ExceptionMessage); AddIfNotNull(HResult); AddIfNotNull(BuildEngineVersion); AddIfNotNull(BuildEngineFrameworkName); @@ -274,10 +359,19 @@ public Dictionary GetActivityProperties() telemetryItems.Add(nameof(CrashOrigin), CrashOrigin.ToString()); } AddIfNotNull(CrashOriginNamespace); + AddIfNotNull(CrashThreadName); AddIfNotNull(InnermostExceptionType); AddIfNotNull(ProcessWorkingSetMB); AddIfNotNull(MemoryLoadPercent); + // EndBuild hang diagnostic properties + AddIfNotNull(EndBuildWaitPhase); + AddIfNotNull(EndBuildWaitDurationMs); + AddIfNotNull(PendingSubmissionCount); + AddIfNotNull(SubmissionsWithResultNoLogging); + AddIfNotNull(ThreadExceptionRecorded); + AddIfNotNull(UnmatchedProjectStartedCount); + return telemetryItems; void AddIfNotNull(object? value, [CallerArgumentExpression(nameof(value))] string key = "") @@ -303,6 +397,9 @@ public override IDictionary GetProperties() AddIfNotNull(IsUnhandled.ToString(), nameof(IsUnhandled)); AddIfNotNull(StackHash); AddIfNotNull(StackTop); + AddIfNotNull(StackCaller); + AddIfNotNull(FullStackTrace); + AddIfNotNull(ExceptionMessage); AddIfNotNull(HResult?.ToString(), nameof(HResult)); AddIfNotNull(BuildEngineVersion); AddIfNotNull(BuildEngineFrameworkName); @@ -312,10 +409,19 @@ public override IDictionary GetProperties() AddIfNotNull(CrashOrigin.ToString(), nameof(CrashOrigin)); } AddIfNotNull(CrashOriginNamespace); + AddIfNotNull(CrashThreadName); AddIfNotNull(InnermostExceptionType); AddIfNotNull(ProcessWorkingSetMB?.ToString(), nameof(ProcessWorkingSetMB)); AddIfNotNull(MemoryLoadPercent?.ToString(), nameof(MemoryLoadPercent)); + // EndBuild hang diagnostic properties + AddIfNotNull(EndBuildWaitPhase); + AddIfNotNull(PendingSubmissionCount?.ToString(), nameof(PendingSubmissionCount)); + AddIfNotNull(SubmissionsWithResultNoLogging?.ToString(), nameof(SubmissionsWithResultNoLogging)); + AddIfNotNull(EndBuildWaitDurationMs?.ToString(), nameof(EndBuildWaitDurationMs)); + AddIfNotNull(ThreadExceptionRecorded?.ToString(), nameof(ThreadExceptionRecorded)); + AddIfNotNull(UnmatchedProjectStartedCount?.ToString(), nameof(UnmatchedProjectStartedCount)); + return properties; void AddIfNotNull(string? value, [CallerArgumentExpression(nameof(value))] string key = "") @@ -514,6 +620,53 @@ internal static CrashOriginKind ClassifyOrigin(string? originNamespace) #endif } + /// + /// Truncates the exception message and sanitizes file paths to avoid sending PII. + /// Some ThrowInternalError call sites embed file paths (e.g., project paths, SDK paths) + /// in the message, which may contain usernames or other PII. + /// + internal static string? TruncateMessage(string? message) + { + if (string.IsNullOrEmpty(message)) + { + return null; + } + + // Strip the "MSB0001: Internal MSBuild Error: " prefix that InternalErrorException prepends. + const string internalErrorPrefix = "MSB0001: Internal MSBuild Error: "; + if (message!.StartsWith(internalErrorPrefix, StringComparison.Ordinal)) + { + message = message.Substring(internalErrorPrefix.Length); + } + + // Redact file/directory paths that may contain PII (e.g., C:\Users\johndoe\...). + // Matches Windows paths (X:\...) and Unix paths (/home/...). + message = System.Text.RegularExpressions.Regex.Replace( + message, + @"(?:[A-Za-z]:\\|/)(?:[^\s""'<>|*?]+)", + ""); + + const int maxLength = 256; + return message.Length <= maxLength ? message : message.Substring(0, maxLength); + } + + /// + /// Known throw-helper method suffixes. When the top stack frame ends with one of + /// these, will skip it and return the next frame. + /// These are methods that only exist to format and throw an exception — the real + /// bug is always in their caller. + /// + private static readonly string[] s_throwHelperSuffixes = + [ + "ErrorUtilities.ThrowInternalError(", + "ErrorUtilities.VerifyThrowInternalError(", + "ErrorUtilities.ThrowInternalErrorUnreachable(", + "ErrorUtilities.VerifyThrowInternalErrorUnreachable(", + "ErrorUtilities.VerifyThrowInternalNull(", + "ErrorUtilities.ThrowInvalidOperation(", + "ErrorUtilities.VerifyThrow(", + ]; + /// /// Extracts the top frame of the stack trace to identify the crash location. /// @@ -531,6 +684,77 @@ internal static CrashOriginKind ClassifyOrigin(string? originNamespace) return SanitizeStackFrame(topFrame.Trim()); } + /// + /// Extracts and sanitizes the full stack trace from the exception. + /// Each frame has file paths redacted. Truncated to . + /// + internal static string? ExtractFullStackTrace(Exception exception) + { + string? stackTrace = exception.StackTrace; + if (string.IsNullOrEmpty(stackTrace)) + { + return null; + } + + string sanitized = SanitizeFilePathsInText(stackTrace!); + + if (sanitized.Length > MaxStackTraceLength) + { + const string truncationSuffix = "... [truncated]"; + sanitized = sanitized.Substring(0, MaxStackTraceLength - truncationSuffix.Length) + truncationSuffix; + } + + return sanitized; + } + + /// + /// If the top stack frame is a known throw-helper (e.g., ErrorUtilities.ThrowInternalError), + /// extracts the next frame — the actual caller where the bug lives. + /// Returns null if the top frame is not a throw-helper or no further frames exist. + /// + internal static string? ExtractStackCaller(Exception exception) + { + string? stackTrace = exception.StackTrace; + if (stackTrace is null) + { + return null; + } + + // Check if the first frame is a known throw-helper. + int firstNewLine = stackTrace.IndexOf('\n'); + string firstFrame = (firstNewLine >= 0 ? stackTrace.Substring(0, firstNewLine) : stackTrace).Trim(); + + bool isThrowHelper = false; + foreach (string suffix in s_throwHelperSuffixes) + { + if (firstFrame.IndexOf(suffix, StringComparison.Ordinal) >= 0) + { + isThrowHelper = true; + break; + } + } + + if (!isThrowHelper || firstNewLine < 0) + { + return null; + } + + // Extract the second frame (the caller of the throw-helper). + int secondStart = firstNewLine + 1; + if (secondStart >= stackTrace.Length) + { + return null; + } + + int secondNewLine = stackTrace.IndexOf('\n', secondStart); + string secondFrame = secondNewLine >= 0 + ? stackTrace.Substring(secondStart, secondNewLine - secondStart) + : stackTrace.Substring(secondStart); + + string trimmed = secondFrame.Trim(); + return trimmed.Length > 0 ? SanitizeStackFrame(trimmed) : null; + } + /// /// Redacts file paths from a stack frame to avoid leaking PII (e.g. usernames in paths). /// Preserves the method signature and line number. @@ -563,4 +787,40 @@ private static string SanitizeStackFrame(string frame) string lineSuffix = frame.Substring(lineIndex); return prefix + "" + lineSuffix; } + + /// + /// Sanitizes file paths embedded in multi-line text (e.g., exception dumps) to remove PII. + /// Each line that looks like a stack frame gets its file path redacted. + /// + internal static string SanitizeFilePathsInText(string text) + { + string[] lines = text.Split('\n'); + for (int i = 0; i < lines.Length; i++) + { + string line = lines[i]; + + // Sanitize " in :line N" patterns (stack frames) + const string inToken = " in "; + const string lineToken = ":line "; + + int inIndex = line.IndexOf(inToken, StringComparison.Ordinal); + if (inIndex >= 0) + { + int lineIndex = line.IndexOf(lineToken, inIndex, StringComparison.Ordinal); + if (lineIndex >= 0) + { + string prefix = line.Substring(0, inIndex + inToken.Length); + string lineSuffix = line.Substring(lineIndex); + lines[i] = prefix + "" + lineSuffix; + } + else + { + // " in " without ":line N" + lines[i] = line.Substring(0, inIndex + inToken.Length) + ""; + } + } + } + + return string.Join("\n", lines); + } } diff --git a/src/Framework/Telemetry/CrashTelemetryRecorder.cs b/src/Framework/Telemetry/CrashTelemetryRecorder.cs index 16e89033f28..dc1a16ba9f5 100644 --- a/src/Framework/Telemetry/CrashTelemetryRecorder.cs +++ b/src/Framework/Telemetry/CrashTelemetryRecorder.cs @@ -15,6 +15,12 @@ namespace Microsoft.Build.Framework.Telemetry; /// internal static class CrashTelemetryRecorder { + /// + /// Interval in milliseconds between EndBuild hang diagnostic emissions. + /// When EndBuild is stuck waiting for submissions or nodes, diagnostics are emitted at this interval. + /// + public const int EndBuildHangDiagnosticsIntervalMs = 30_000; + /// /// Records crash telemetry data for later emission via . /// @@ -173,4 +179,50 @@ private static CrashTelemetry CreateCrashTelemetry( crashTelemetry.IsUnhandled = isUnhandled; return crashTelemetry; } + + /// + /// Collects and emits diagnostic telemetry when EndBuild is stuck waiting. + /// Called periodically from timed wait loops so that diagnostics are available + /// even if the hang never resolves (crash telemetry in the finally block would be unreachable). + /// + [MethodImpl(MethodImplOptions.NoInlining)] + public static void CollectAndEmitEndBuildHangDiagnostics( + string waitPhase, + long waitDurationMs, + int pendingSubmissionCount, + int submissionsWithResultNoLogging, + bool threadExceptionRecorded, + int unmatchedProjectStartedCount, + string? buildEngineVersion, + string? buildEngineFrameworkName, + string? buildEngineHost) + { + try + { + var crashTelemetry = new CrashTelemetry + { + ExitType = CrashExitType.EndBuildHang, + BuildEngineVersion = buildEngineVersion, + BuildEngineFrameworkName = buildEngineFrameworkName, + BuildEngineHost = buildEngineHost, + EndBuildWaitPhase = waitPhase, + EndBuildWaitDurationMs = waitDurationMs, + PendingSubmissionCount = pendingSubmissionCount, + SubmissionsWithResultNoLogging = submissionsWithResultNoLogging, + ThreadExceptionRecorded = threadExceptionRecorded, + UnmatchedProjectStartedCount = unmatchedProjectStartedCount, + }; + + TelemetryManager.Instance?.Initialize(isStandalone: false); + + using IActivity? activity = TelemetryManager.Instance + ?.DefaultActivitySource + ?.StartActivity(TelemetryConstants.Crash); + activity?.SetTags(crashTelemetry); + } + catch + { + // Best effort: diagnostic telemetry must never cause a secondary failure. + } + } } diff --git a/src/Shared/ExceptionHandling.cs b/src/Shared/ExceptionHandling.cs index 77383b611cd..66bbb1460b8 100644 --- a/src/Shared/ExceptionHandling.cs +++ b/src/Shared/ExceptionHandling.cs @@ -422,6 +422,33 @@ internal static void DumpExceptionToFile(Exception ex) } } + /// + /// Writes hang diagnostic information to a file so it persists on disk + /// for later retrieval from customer machines. + /// File is written to the same directory as crash dump files (). + /// + internal static void DumpHangDiagnosticsToFile(string diagnostics) + { + try + { + Directory.CreateDirectory(DebugDumpPath); + + var pid = EnvironmentUtilities.CurrentProcessId; + string fileName = Path.Combine(DebugDumpPath, $"MSBuild_pid-{pid}.hang.txt"); + + using (StreamWriter writer = FileUtilities.OpenWrite(fileName, append: true)) + { + writer.WriteLine(DateTime.Now.ToString("G", CultureInfo.CurrentCulture)); + writer.WriteLine(diagnostics); + writer.WriteLine("==================="); + } + } + catch + { + // Best-effort: diagnostic file writing must never make things worse. + } + } + /// /// Returns the content of any exception dump files modified /// since the provided time, otherwise returns an empty string.