diff --git a/Public/Src/App/Bxl/AzureDevOpsListener.cs b/Public/Src/App/Bxl/AzureDevOpsListener.cs index 5a0617c46..a90a376a5 100644 --- a/Public/Src/App/Bxl/AzureDevOpsListener.cs +++ b/Public/Src/App/Bxl/AzureDevOpsListener.cs @@ -167,7 +167,7 @@ namespace BuildXL if (actualEventId == (int)LogEventId.PipProcessError) { var pipProcessErrorEventFields = new PipProcessErrorEventFields(eventData.Payload, true); - addPipErrors(pipProcessErrorEventFields, (string)eventData.Payload[15]); + addPipErrors(pipProcessErrorEventFields, (string)eventData.Payload[16]); } } break; @@ -175,7 +175,7 @@ namespace BuildXL void addPipErrors(PipProcessErrorEventFields pipProcessErrorEventFields, string workerId) { - var semiStableHash = Pip.FormatSemiStableHash(pipProcessErrorEventFields.PipSemiStableHash); + string semiStableHash = Pip.FormatSemiStableHash(pipProcessErrorEventFields.PipSemiStableHash); m_buildViewModel.BuildSummary.AddPipError(new BuildSummaryPipDiagnostic { SemiStablePipId = semiStableHash, @@ -193,6 +193,8 @@ namespace BuildXL TargetId = semiStableHash, StdOutputPath = pipProcessErrorEventFields.OutputToLog, PipDescription = pipProcessErrorEventFields.PipDescription, + ShortPipDescription = pipProcessErrorEventFields.ShortPipDescription, + PipExecutionTimeMs = pipProcessErrorEventFields.PipExecutionTimeMs }); } } diff --git a/Public/Src/App/UnitTests/Bxl/DevOpsListenerTests.cs b/Public/Src/App/UnitTests/Bxl/DevOpsListenerTests.cs index e5bbf0b90..d0e5fe5f9 100644 --- a/Public/Src/App/UnitTests/Bxl/DevOpsListenerTests.cs +++ b/Public/Src/App/UnitTests/Bxl/DevOpsListenerTests.cs @@ -79,7 +79,7 @@ namespace Test.BuildXL var eventName = "PipProcessError"; var text = "Pip process error message"; var pipSemiStableHash = (long)24; - + m_eventListener.RegisterEventSource(global::BuildXL.Engine.ETWLogger.Log); m_eventListener.NestedLoggerHandler += eventData => { @@ -119,6 +119,7 @@ namespace Test.BuildXL public static PipProcessErrorTestElement Create(BuildXLTestBase testBase) { var result = new PipProcessErrorTestElement(); + long totalElapsedTimeMs = Convert.ToInt64(TimeSpan.FromSeconds(15).TotalMilliseconds); var pipProcessError = new PipProcessErrorEventFields( (long)24, "my cool pip", @@ -130,7 +131,8 @@ namespace Test.BuildXL @"specs\workingDir\out.txt", -1, "what does this do?", - "my pip"); + "my pip", + totalElapsedTimeMs); var processedOutputToLog = "Failure message Line1%0D%0A##[error]Failure message Line2%0D##[error]Failure message Line3%0A##[error]"; result.ExpectingConsoleLog = @$"##vso[task.logIssue type=error;]DX0064 [Pip0000000000000018, {pipProcessError.ShortPipDescription}, {pipProcessError.PipSpecPath}] - failed with exit code {pipProcessError.ExitCode}, {pipProcessError.OptionalMessage}%0D%0A##[error]{processedOutputToLog}%0D%0A##[error]{pipProcessError.MessageAboutPathsToLog}%0D%0A##[error]{pipProcessError.PathsToLog}"; @@ -157,7 +159,8 @@ namespace Test.BuildXL PipProcessError.PathsToLog, PipProcessError.ExitCode, PipProcessError.OptionalMessage, - PipProcessError.ShortPipDescription); + PipProcessError.ShortPipDescription, + PipProcessError.PipExecutionTimeMs); } public void Dispose() diff --git a/Public/Src/Engine/Cache/Fingerprints/OpenBondDistribution.bond b/Public/Src/Engine/Cache/Fingerprints/OpenBondDistribution.bond index 20f057b4d..a7b22c57d 100644 --- a/Public/Src/Engine/Cache/Fingerprints/OpenBondDistribution.bond +++ b/Public/Src/Engine/Cache/Fingerprints/OpenBondDistribution.bond @@ -130,6 +130,7 @@ struct PipProcessErrorEvent 9: int32 ExitCode; 10: string OptionalMessage; 11: string ShortPipDescription; + 12: int64 PipExecutionTimeMs; } /// Events that have been logged on workers and are transited to the orchestrator. Any changes here may require changes diff --git a/Public/Src/Engine/Distribution.Grpc/Interfaces.proto b/Public/Src/Engine/Distribution.Grpc/Interfaces.proto index 3b233b1c4..24cea56da 100644 --- a/Public/Src/Engine/Distribution.Grpc/Interfaces.proto +++ b/Public/Src/Engine/Distribution.Grpc/Interfaces.proto @@ -309,4 +309,5 @@ message PipProcessErrorEvent { int32 ExitCode = 9; string OptionalMessage = 10; string ShortPipDescription = 11; + int64 PipExecutionTimeMs = 12; } \ No newline at end of file diff --git a/Public/Src/Engine/Dll/Distribution/Grpc/OpenBondConversionUtils.cs b/Public/Src/Engine/Dll/Distribution/Grpc/OpenBondConversionUtils.cs index 331a47e5e..afca86597 100644 --- a/Public/Src/Engine/Dll/Distribution/Grpc/OpenBondConversionUtils.cs +++ b/Public/Src/Engine/Dll/Distribution/Grpc/OpenBondConversionUtils.cs @@ -97,7 +97,8 @@ namespace BuildXL.Engine.Distribution.Grpc PathsToLog = i.PipProcessErrorEvent.PathsToLog, ExitCode = i.PipProcessErrorEvent.ExitCode, OptionalMessage = i.PipProcessErrorEvent.OptionalMessage, - ShortPipDescription = i.PipProcessErrorEvent.ShortPipDescription + ShortPipDescription = i.PipProcessErrorEvent.ShortPipDescription, + PipExecutionTimeMs = i.PipProcessErrorEvent.PipExecutionTimeMs }; } @@ -147,7 +148,8 @@ namespace BuildXL.Engine.Distribution.Grpc PathsToLog = i.PipProcessErrorEvent.PathsToLog, ExitCode = i.PipProcessErrorEvent.ExitCode, OptionalMessage = i.PipProcessErrorEvent.OptionalMessage, - ShortPipDescription = i.PipProcessErrorEvent.ShortPipDescription + ShortPipDescription = i.PipProcessErrorEvent.ShortPipDescription, + PipExecutionTimeMs = i.PipProcessErrorEvent.PipExecutionTimeMs } : null, }); } diff --git a/Public/Src/Engine/Dll/Distribution/OrchestratorService.cs b/Public/Src/Engine/Dll/Distribution/OrchestratorService.cs index 0e8b69f08..a3ca9cede 100644 --- a/Public/Src/Engine/Dll/Distribution/OrchestratorService.cs +++ b/Public/Src/Engine/Dll/Distribution/OrchestratorService.cs @@ -194,7 +194,9 @@ namespace BuildXL.Engine.Distribution forwardedEvent.PipProcessErrorEvent.PathsToLog, forwardedEvent.PipProcessErrorEvent.ExitCode, forwardedEvent.PipProcessErrorEvent.OptionalMessage, - forwardedEvent.PipProcessErrorEvent.ShortPipDescription); + forwardedEvent.PipProcessErrorEvent.ShortPipDescription, + forwardedEvent.PipProcessErrorEvent.PipExecutionTimeMs + ); logForwardedError( m_loggingContext, diff --git a/Public/Src/Engine/Dll/Distribution/WorkerNotificationManager.EventListener.cs b/Public/Src/Engine/Dll/Distribution/WorkerNotificationManager.EventListener.cs index 7927fdca1..f61d859af 100644 --- a/Public/Src/Engine/Dll/Distribution/WorkerNotificationManager.EventListener.cs +++ b/Public/Src/Engine/Dll/Distribution/WorkerNotificationManager.EventListener.cs @@ -74,6 +74,7 @@ namespace BuildXL.Engine.Distribution ExitCode = pipProcessErrorEventFields.ExitCode, OptionalMessage = pipProcessErrorEventFields.OptionalMessage, ShortPipDescription = pipProcessErrorEventFields.ShortPipDescription, + PipExecutionTimeMs = pipProcessErrorEventFields.PipExecutionTimeMs }; } diff --git a/Public/Src/Engine/Processes/SandboxedProcessPipExecutor.cs b/Public/Src/Engine/Processes/SandboxedProcessPipExecutor.cs index 19921e0db..7b71ca76b 100644 --- a/Public/Src/Engine/Processes/SandboxedProcessPipExecutor.cs +++ b/Public/Src/Engine/Processes/SandboxedProcessPipExecutor.cs @@ -4985,6 +4985,8 @@ namespace BuildXL.Processes EventConstants.PipProcessErrorWroteToStandardError : string.Empty; + long totalElapsedTimeMS = Convert.ToInt64(result.PrimaryProcessTimes.TotalWallClockTime.TotalMilliseconds); + Tracing.Logger.Log.PipProcessError( m_loggingContext, m_pip.SemiStableHash, @@ -4996,8 +4998,10 @@ namespace BuildXL.Processes messageAboutPathsToLog, AddTrailingNewLineIfNeeded(outputPathsToLog), result.ExitCode, - optionalMessage, - m_pip.GetShortDescription(m_context)); + optionalMessage, + m_pip.GetShortDescription(m_context), + totalElapsedTimeMS); + } private void HandleErrorsFromTool(string error) diff --git a/Public/Src/Engine/Processes/Tracing/Log.cs b/Public/Src/Engine/Processes/Tracing/Log.cs index 1de0a3aa1..0a94e5f6a 100644 --- a/Public/Src/Engine/Processes/Tracing/Log.cs +++ b/Public/Src/Engine/Processes/Tracing/Log.cs @@ -798,8 +798,8 @@ namespace BuildXL.Processes.Tracing LoggingContext context, // CAUTION!!! - // ConsoleEventListener opens up the payload array to pluck off various members. It must be updated - // if the order or type of these parameters change + // Refer PipProcessErrorEventFields.cs if any of these fields or the order is changed. + // A reference to a field still remains in ConsoleEventListener.cs please refer to that when the fields or the order is changed. long pipSemiStableHash, string pipDescription, string pipSpecPath, @@ -809,8 +809,9 @@ namespace BuildXL.Processes.Tracing string messageAboutPathsToLog, string pathsToLog, int exitCode, - string optionalMessage, - string shortPipDescription); + string optionalMessage, + string shortPipDescription, + long pipExecutionTimeMs); [GeneratedEvent( (int)LogEventId.PipProcessWarning, diff --git a/Public/Src/Utilities/Instrumentation/Common/PipProcessErrorEventFields.cs b/Public/Src/Utilities/Instrumentation/Common/PipProcessErrorEventFields.cs index 0ab97f862..820f25876 100644 --- a/Public/Src/Utilities/Instrumentation/Common/PipProcessErrorEventFields.cs +++ b/Public/Src/Utilities/Instrumentation/Common/PipProcessErrorEventFields.cs @@ -45,6 +45,9 @@ namespace BuildXL.Utilities.Instrumentation.Common /// public string ShortPipDescription { get; } + /// + public long PipExecutionTimeMs { get; } + /// /// Construct PipProcessErrorEventFields from eventPayload /// @@ -66,6 +69,7 @@ namespace BuildXL.Utilities.Instrumentation.Common OptionalMessage = (string)eventPayload[9 + startIndex]; ShortPipDescription = (string)eventPayload[10 + startIndex]; + PipExecutionTimeMs = (long)eventPayload[11 + startIndex]; #pragma warning restore CS8600 #pragma warning restore CS8601 @@ -89,7 +93,8 @@ namespace BuildXL.Utilities.Instrumentation.Common string pathsToLog, int exitCode, string optionalMessage, - string shortPipDescription + string shortPipDescription, + long pipExecutionTimeMs ) { PipSemiStableHash = pipSemiStableHash; @@ -103,6 +108,7 @@ namespace BuildXL.Utilities.Instrumentation.Common ExitCode = exitCode; OptionalMessage = optionalMessage; ShortPipDescription = shortPipDescription; + PipExecutionTimeMs = pipExecutionTimeMs; } } } \ No newline at end of file diff --git a/Public/Src/Utilities/Instrumentation/Tracing/Events/TargetFailedEvent.cs b/Public/Src/Utilities/Instrumentation/Tracing/Events/TargetFailedEvent.cs index b751b9556..bbc9e9d54 100644 --- a/Public/Src/Utilities/Instrumentation/Tracing/Events/TargetFailedEvent.cs +++ b/Public/Src/Utilities/Instrumentation/Tracing/Events/TargetFailedEvent.cs @@ -24,7 +24,7 @@ namespace BuildXL.Tracing.CloudBuild /// /// WARNING: INCREMENT IF YOU UPDATE THE PRIMITIVE MEMBERS! /// - public override int Version { get; set; } = 2; + public override int Version { get; set; } = 3; /// public override EventKind Kind { get; set; } = EventKind.TargetFailed; @@ -59,5 +59,15 @@ namespace BuildXL.Tracing.CloudBuild /// public string? StdOutputPath { get; set; } + /// + /// Short Pip Description for Target Error Path + /// + public string? ShortPipDescription { get; set; } + + /// + /// PipExecutionTime + /// + public long PipExecutionTimeMs { get; set; } + } }