Skip to content

Commit

Permalink
Merged PR 730784: Revert "Merged PR 727953: More robust execution-log…
Browse files Browse the repository at this point in the history
… event serialization

Revert "Merged PR 727953: More robust execution-log event serialization

This PR makes serialization of execution-log event serialization more robust by handling the exception, e.g., OutOfMemory exception, that can happen during serialization.

In the case of an exception, the event is skipped, and users are given a warning about this.

Related work items: #2081944"

Reverted commit `e2ca19cb`.

Related work items: #2081944
  • Loading branch information
Oleksii Kononenko committed Jul 31, 2023
1 parent c51e769 commit b6f9c90
Show file tree
Hide file tree
Showing 6 changed files with 92 additions and 355 deletions.
79 changes: 17 additions & 62 deletions Public/Src/Engine/Scheduler/Tracing/ExecutionLog.Events.cs
Original file line number Diff line number Diff line change
Expand Up @@ -129,11 +129,6 @@ public interface IExecutionLogTarget : IDisposable
/// Build Manifest hash and relative file path is reported
/// </summary>
void RecordFileForBuildManifest(RecordFileForBuildManifestEventData data);

/// <summary>
/// Test custom event. Used only by unit tests.
/// </summary>
void TestCustom(TestCustomEventData data);
}

/// <summary>
Expand Down Expand Up @@ -220,11 +215,6 @@ public enum ExecutionEventId : byte
/// See <see cref="IExecutionLogTarget.DynamicDirectoryContentsDecided"/>
/// </summary>
DynamicDirectoryContentsDecided = 16,

/// <summary>
/// See <see cref="IExecutionLogTarget.TestCustom"/>
/// </summary>
TestCustom = 17,
}

/// <summary>
Expand Down Expand Up @@ -354,36 +344,27 @@ public static class ExecutionLogMetadata
ExecutionEventId.RecordFileForBuildManifest,
(data, target) => target.RecordFileForBuildManifest(data));

/// <summary>
/// Event description for <see cref="IExecutionLogTarget.PipExecutionDirectoryOutputs"/>
/// </summary>
public static readonly ExecutionLogEventMetadata<TestCustomEventData> TestCustom =
new ExecutionLogEventMetadata<TestCustomEventData>(
ExecutionEventId.TestCustom,
(data, target) => target.TestCustom(data));

/// <summary>
/// All execution log events.
/// </summary>
public static readonly IReadOnlyList<ExecutionLogEventMetadata> Events = new ExecutionLogEventMetadata[]
{
BxlInvocation,
FileArtifactContentDecided,
WorkerList,
PipExecutionPerformance,
DirectoryMembershipHashed,
ProcessExecutionMonitoringReported,
BuildSessionConfiguration,
DependencyViolationReported,
PipExecutionStepPerformanceReported,
ProcessFingerprintComputation,
PipCacheMiss,
PipExecutionDirectoryOutputs,
CacheMaterializationError,
RecordFileForBuildManifest,
DynamicDirectoryContentsDecided,
TestCustom,
};
{
BxlInvocation,
FileArtifactContentDecided,
WorkerList,
PipExecutionPerformance,
DirectoryMembershipHashed,
ProcessExecutionMonitoringReported,
BuildSessionConfiguration,
DependencyViolationReported,
PipExecutionStepPerformanceReported,
ProcessFingerprintComputation,
PipCacheMiss,
PipExecutionDirectoryOutputs,
CacheMaterializationError,
RecordFileForBuildManifest,
DynamicDirectoryContentsDecided
};
}

/// <summary>
Expand Down Expand Up @@ -1482,30 +1463,4 @@ public void DeserializeAndUpdate(BinaryLogReader.EventReader reader)
r => (reader.ReadFileArtifact(), new ContentHash(reader)));
}
}

/// <summary>
/// Custom event for testing purposes.
/// </summary>
[SuppressMessage("Microsoft.Performance", "CA1815:OverrideEqualsAndOperatorEqualsOnValueTypes")]
public struct TestCustomEventData : IExecutionLogEventData<TestCustomEventData>
{
/// <summary>
/// Custom serialization function.
/// </summary>
public static Action<BinaryLogger.EventWriter> SerializeFunc;

/// <summary>
/// Custom deserialization function.
/// </summary>
public static Action<BinaryLogReader.EventReader> DeserializeAndUpdateFunc;

/// <inheritdoc />
public ExecutionLogEventMetadata<TestCustomEventData> Metadata => ExecutionLogMetadata.TestCustom;

/// <inheritdoc />
public void DeserializeAndUpdate(BinaryLogReader.EventReader reader) => DeserializeAndUpdateFunc(reader);

/// <inheritdoc />
public void Serialize(BinaryLogger.EventWriter writer) => SerializeFunc(writer);
}
}
28 changes: 7 additions & 21 deletions Public/Src/Engine/Scheduler/Tracing/ExecutionLog.cs
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
using System.Collections.Generic;
using System.Diagnostics.ContractsLight;
using System.IO;
using BuildXL.Utilities;
using BuildXL.Utilities.Core;
using BuildXL.Utilities.Tracing;
using static BuildXL.Utilities.Core.FormattableStringEx;
Expand Down Expand Up @@ -241,12 +242,6 @@ public virtual void DynamicDirectoryContentsDecided(DynamicDirectoryContentsDeci
{
ReportUnhandledEvent(data);
}

/// <nodoc />
public virtual void TestCustom(TestCustomEventData data)
{
ReportUnhandledEvent(data);
}
}

/// <summary>
Expand All @@ -266,7 +261,10 @@ public abstract class ExecutionLogEventMetadata
public readonly ExecutionEventId EventId;

/// <nodoc />
protected ExecutionLogEventMetadata(ExecutionEventId eventId) => EventId = eventId;
protected ExecutionLogEventMetadata(ExecutionEventId eventId)
{
EventId = eventId;
}

/// <summary>
/// Translates a serialized stream containing an event (of this type) into an invocation on an <see cref="IExecutionLogTarget"/>.
Expand Down Expand Up @@ -295,7 +293,7 @@ public ExecutionLogEventMetadata(ExecutionEventId eventId, Action<TEventData, IE
/// <inheritdoc />
public override void DeserializeAndLogToTarget(BinaryLogReader.EventReader eventReader, IExecutionLogTarget target)
{
TEventData data = default;
TEventData data = default(TEventData);
data.DeserializeAndUpdate(eventReader);
m_process(data, target);
}
Expand Down Expand Up @@ -387,19 +385,7 @@ private void Log<TEventData>(TEventData data) where TEventData : struct, IExecut
{
using (BinaryLogger.EventScope eventScope = m_logFile.StartEvent((uint)data.Metadata.EventId, m_workerId))
{

try
{
data.Serialize(eventScope.Writer);
}
catch (Exception e)
{
// Set exception so that event is not serialized to the log file.
eventScope.SetException(e);

// Inform users that an event is not logged due to an exception.
Logger.Log.FailedLoggingExecutionLogEventData(Events.StaticContext, data.Metadata.EventId.ToString(), e.ToString());
}
data.Serialize(eventScope.Writer);
}
}

Expand Down
33 changes: 12 additions & 21 deletions Public/Src/Engine/Scheduler/Tracing/Log.cs
Original file line number Diff line number Diff line change
Expand Up @@ -3975,31 +3975,22 @@ internal abstract void ProcessPipExecutionInfo(
internal abstract void UnableToMonitorDriveWithSubst(LoggingContext loggingContext, string path, string drive);

[GeneratedEvent(
(ushort)LogEventId.SchedulerCompleteExceptMaterializeOutputs,
EventGenerators = EventGenerators.LocalOnly,
EventLevel = Level.Verbose,
Keywords = (int)Keywords.UserMessage,
EventTask = (ushort)Tasks.Scheduler,
Message = "The scheduler has been marked completed except for MaterializeOutput pip steps")]
(ushort)LogEventId.SchedulerCompleteExceptMaterializeOutputs,
EventGenerators = EventGenerators.LocalOnly,
EventLevel = Level.Verbose,
Keywords = (int)Keywords.UserMessage,
EventTask = (ushort)Tasks.Scheduler,
Message = "The scheduler has been marked completed except for MaterializeOutput pip steps")]
internal abstract void SchedulerCompleteExceptMaterializeOutputs(LoggingContext loggingContext);

[GeneratedEvent(
(ushort)LogEventId.CreationTimeNotSupported,
EventGenerators = EventGenerators.LocalOnly,
EventLevel = Level.Verbose,
Keywords = (int)Keywords.UserMessage,
EventTask = (ushort)Tasks.Scheduler,
Message = "File creation time retrieval is not supported by the underlying operating system. Some optimizations will be disabled.")]
(ushort)LogEventId.CreationTimeNotSupported,
EventGenerators = EventGenerators.LocalOnly,
EventLevel = Level.Verbose,
Keywords = (int)Keywords.UserMessage,
EventTask = (ushort)Tasks.Scheduler,
Message = "File creation time retrieval is not supported by the underlying operating system. Some optimizations will be disabled.")]
internal abstract void CreationTimeNotSupported(LoggingContext loggingContext);

[GeneratedEvent(
(ushort)LogEventId.FailedLoggingExecutionLogEventData,
EventGenerators = EventGenerators.LocalOnly,
EventLevel = Level.Warning,
Keywords = (int)Keywords.UserMessage,
EventTask = (ushort)Tasks.Scheduler,
Message = "Failed logging execution log event data '{eventId}'. This does not impact build correctness but will cause the execution log to be incomplete for post-build analysis. Failure reason: {error}")]
internal abstract void FailedLoggingExecutionLogEventData(LoggingContext loggingContext, string eventId, string error);
}
}
#pragma warning restore CA1823 // Unused field
1 change: 0 additions & 1 deletion Public/Src/Engine/Scheduler/Tracing/LogEventId.cs
Original file line number Diff line number Diff line change
Expand Up @@ -520,7 +520,6 @@ public enum LogEventId : ushort
FailedToDeserializeLRUMap = 14536,

CreationTimeNotSupported = 14537,
FailedLoggingExecutionLogEventData = 14538,

// was DependencyViolationGenericWithRelatedPip_AsError = 25000,
// was DependencyViolationGeneric_AsError = 25001,
Expand Down
Loading

0 comments on commit b6f9c90

Please sign in to comment.