diff --git a/documentation/wiki/Binary-Log.md b/documentation/wiki/Binary-Log.md index 9edcddc6fd4..d9bb101159f 100644 --- a/documentation/wiki/Binary-Log.md +++ b/documentation/wiki/Binary-Log.md @@ -84,7 +84,7 @@ It is a `GZipStream`-compressed binary stream of serialized `BuildEventArgs` obj ## Incrementing the file format -Every .binlog file has the first three bytes that indicate the file version. The current file format version is 9 (`00 00 09`). +Every .binlog file has the first four bytes that indicate the file version. The current file format is indicated in [`BinaryLogger.cs`](/src/Build/Logging/BinaryLogger/BinaryLogger.cs). When incrementing the file format, keep this in mind: * Increment the version and add a summary of the changes: https://github.com/dotnet/msbuild/blob/main/src/Build/Logging/BinaryLogger/BinaryLogger.cs#L22 @@ -94,4 +94,98 @@ When incrementing the file format, keep this in mind: The format is backwards compatible, i.e. MSBuild will be able to play back .binlog files created with an older version of MSBuild. The Viewer will also be able to open files of any older version. Since the viewer updates automatically and I can push out updates easily, we can consider the Viewer is always able to read all .binlogs. -However MSBuild of version 15.3 won't be able to read .binlogs created with MSBuild version 15.6. This means the format is unfortunately not forwards-compatible. It is not self-describing, i.e. it doesn't carry its schema around for performance and compactness reasons. This is not a problem with a Viewer because Viewer is always up-to-date (there isn't an "old version" of the Viewer unless people go to great lengths to prevent it from auto-updating). +## Forward compatibility reading + +From version 18, the binlog contains as well the minimum version of reader that can interpret it (stored in bytes 4 to 8). Support for best effort forward compatibility is added by this version. It is “best effort” only because the binlog format is not self-describing, i.e. it doesn't carry its schema around for performance and compactness reasons. + +This is not of a high importance for users of the Viewer because Viewer is always up-to-date (there isn't an "old version" of the Viewer unless people go to great lengths to prevent it from auto-updating). + +## Reading API + +We recommend usage of `BinaryLogReplayEventSource`. It provides simplified helpers for creating and configuring `BuildEventArgsReader` and subscribing to the events. + +```csharp +var logReader = new BinaryLogReplayEventSource() +{ + AllowForwardCompatibility = true +}; + +// Handling of the structured events contained within the log +logReader.AnyEventRaised += (_, e) => +{ + if (e is BuildErrorEventArgs error) + { + //... + } + + // ... +}; + +// Starts the synchronous log reading loop. +logReader.Replay(path_to_binlog_file); + +``` + +### Handling the recoverable reading errors + +In compatibility mode (default for `BinaryLogReplayEventSource`. Only supported for binlogs of version 18 and higher) reader is capable of skipping unknown event types and unknown parts of known events (`BuildEventArgsReader` can configure the behavior via 2 separate properties - `SkipUnknownEvents` and `SkipUnknownEventParts`). + +The unknown events and event parts are regarded as recoverable errors, since the reader is able to continue reading subsequent records in the binlog. However the specific user logic should have the last call in deciding whether errors are really recoverable (e.g. is presence of unrecognized or unparseable event ok? It might be fine when searching only for specific events - e.g. errors but not acceptable when trying to provide definitive overview of the built). + +To allow the calling code to decide - based on the type of error, type of events getting the error, or the number of errors - the `RecoverableReadError` event is exposed (from both `BinaryLogReplayEventSource` and `BuildEventArgsReader`). + +```csharp +/// +/// An event args for event. +/// +public sealed class BinaryLogReaderErrorEventArgs : EventArgs +{ + /// + /// Type of the error that occurred during reading. + /// + public ReaderErrorType ErrorType { get; } + + /// + /// Kind of the record that encountered the error. + /// + public BinaryLogRecordKind RecordKind { get; } + + /// + /// Materializes the error message. + /// Until it's called the error message is not materialized and no string allocations are made. + /// + /// The error message. + public string GetFormattedMessage() => _formatErrorMessage(); +} + +/// +/// Receives recoverable errors during reading. +/// Communicates type of the error, kind of the record that encountered the error and the message detailing the error. +/// In case of this is raised before returning the structured representation of a build event +/// that has some extra unknown data in the binlog. In case of other error types this event is raised and the offending build event is skipped and not returned. +/// +event Action? RecoverableReadError; +``` + +Our sample usage of the [Reading API](#reading-api) can be enhanced with recoverable errors handling e.g. as such: + +```csharp + +// Those can be raised only during forward compatibility reading mode. +logReader.RecoverableReadError += errorEventArgs => +{ + // ... + + // e.g. we can decide to ignore the error and continue reading or break reading + // based on the type of the error or/and type of the record or/and the frequency of the error + + // Would we decide to completely ignore some errors - we can aid better performance by not materializing the actual error message. + // Otherwise the error message can be materialized via the provided method on the event argument: + Console.WriteLine($"Recoverable reader error: {errorEventArgs.GetFormattedMessage()}"); +}; + +``` + +When authoring changes to the specific BuildEventArg types - it is always strongly recommended to **prefer append-only changes**. + +This prevents the possibility of collision where some fields are removed in one version and then different fields with same binary size are added in future version. Such a sequence of format changes might not be caught by the decoder and might lead to unnoticed corrupt interpretation of data. For this reason the author of specific OM changes should always check whether there is a possibility of unrecognizable format collision (same binary size, different representation) within binlog versions of a same [minimum reader version support](#forward-compatibility-reading). If this is possible, the [minimum reader version support](#forward-compatibility-reading) should be incremented. \ No newline at end of file diff --git a/src/Build.UnitTests/BinaryLogger_Tests.cs b/src/Build.UnitTests/BinaryLogger_Tests.cs index 2693be21f78..ccd837ef921 100644 --- a/src/Build.UnitTests/BinaryLogger_Tests.cs +++ b/src/Build.UnitTests/BinaryLogger_Tests.cs @@ -5,8 +5,10 @@ using System.Collections.Generic; using System.IO; using System.IO.Compression; +using System.Linq; +using System.Reflection; using System.Text; - +using FluentAssertions; using Microsoft.Build.BackEnd.Logging; using Microsoft.Build.Evaluation; using Microsoft.Build.Execution; @@ -83,10 +85,21 @@ public BinaryLoggerTests(ITestOutputHelper output) _logFile = _env.ExpectFile(".binlog").Path; } + public enum BinlogRoundtripTestReplayMode + { + NoReplay, + Structured, + RawEvents + } + [Theory] - [InlineData(s_testProject)] - [InlineData(s_testProject2)] - public void TestBinaryLoggerRoundtrip(string projectText) + [InlineData(s_testProject, BinlogRoundtripTestReplayMode.NoReplay)] + [InlineData(s_testProject, BinlogRoundtripTestReplayMode.Structured)] + [InlineData(s_testProject, BinlogRoundtripTestReplayMode.RawEvents)] + [InlineData(s_testProject2, BinlogRoundtripTestReplayMode.NoReplay)] + [InlineData(s_testProject2, BinlogRoundtripTestReplayMode.Structured)] + [InlineData(s_testProject2, BinlogRoundtripTestReplayMode.RawEvents)] + public void TestBinaryLoggerRoundtrip(string projectText, BinlogRoundtripTestReplayMode replayMode) { var binaryLogger = new BinaryLogger(); @@ -110,6 +123,36 @@ public void TestBinaryLoggerRoundtrip(string projectText) project.Build(new ILogger[] { binaryLogger, mockLogFromBuild, serialFromBuild, parallelFromBuild }).ShouldBeTrue(); } + string fileToReplay; + switch (replayMode) + { + case BinlogRoundtripTestReplayMode.NoReplay: + fileToReplay = _logFile; + break; + case BinlogRoundtripTestReplayMode.Structured: + case BinlogRoundtripTestReplayMode.RawEvents: + { + var logReader = new BinaryLogReplayEventSource(); + fileToReplay = _env.ExpectFile(".binlog").Path; + if (replayMode == BinlogRoundtripTestReplayMode.Structured) + { + // need dummy handler to force structured replay + logReader.BuildFinished += (_, _) => { }; + } + + BinaryLogger outputBinlog = new BinaryLogger() + { + Parameters = fileToReplay + }; + outputBinlog.Initialize(logReader); + logReader.Replay(_logFile); + outputBinlog.Shutdown(); + } + break; + default: + throw new ArgumentOutOfRangeException(nameof(replayMode), replayMode, null); + } + var mockLogFromPlayback = new MockLogger(); var serialFromPlaybackText = new StringBuilder(); @@ -126,7 +169,10 @@ public void TestBinaryLoggerRoundtrip(string projectText) parallelFromPlayback.Initialize(binaryLogReader); // read the binary log and replay into mockLogger2 - binaryLogReader.Replay(_logFile); + binaryLogReader.Replay(fileToReplay); + mockLogFromPlayback.Shutdown(); + serialFromPlayback.Shutdown(); + parallelFromPlayback.Shutdown(); // the binlog will have more information than recorded by the text log mockLogFromPlayback.FullLog.ShouldContainWithoutWhitespace(mockLogFromBuild.FullLog); @@ -140,6 +186,138 @@ public void TestBinaryLoggerRoundtrip(string projectText) parallelActual.ShouldContainWithoutWhitespace(parallelExpected); } + /// + /// This test validate that binlog file content is identical upon replaying. + /// The identity can be defined via 3 ways: + /// * byte-for-byte equality + /// * byte-for-byte equality of unzipped content + /// * structured equality of events + /// + /// They are ordered by their strength (the byte-for-byte equality implies the other two, etc.), + /// but we mainly care about the structured equality. If the more strong equalities are broken - + /// the assertions can be simply removed. + /// However the structured equality is important - it guarantees that binlog reading and writing functionality + /// is not dropping or altering any information. + /// + /// + /// + [Theory] + [InlineData(s_testProject, BinlogRoundtripTestReplayMode.Structured)] + [InlineData(s_testProject, BinlogRoundtripTestReplayMode.RawEvents)] + [InlineData(s_testProject2, BinlogRoundtripTestReplayMode.Structured)] + [InlineData(s_testProject2, BinlogRoundtripTestReplayMode.RawEvents)] + public void TestBinaryLoggerRoundtripEquality(string projectText, BinlogRoundtripTestReplayMode replayMode) + { + var binaryLogger = new BinaryLogger(); + + binaryLogger.Parameters = _logFile; + + // build and log into binary logger + using (ProjectCollection collection = new()) + { + Project project = ObjectModelHelpers.CreateInMemoryProject(collection, projectText); + // make sure the project file makes it to the binlog (it has file existence check) + File.WriteAllText(project.FullPath, projectText); + project.Build(new ILogger[] { binaryLogger }).ShouldBeTrue(); + File.Delete(project.FullPath); + } + + var logReader = new BinaryLogReplayEventSource(); + string replayedLogFile = _env.ExpectFile(".binlog").Path; + if (replayMode == BinlogRoundtripTestReplayMode.Structured) + { + // need dummy handler to force structured replay + logReader.BuildFinished += (_, _) => { }; + } + + BinaryLogger outputBinlog = new BinaryLogger() + { + Parameters = $"LogFile={replayedLogFile};OmitInitialInfo" + }; + outputBinlog.Initialize(logReader); + logReader.Replay(_logFile); + outputBinlog.Shutdown(); + + AssertBinlogsHaveEqualContent(_logFile, replayedLogFile); + // If this assertation complicates development - it can possibly be removed + // The structured equality above should be enough. + AssertFilesAreBinaryEqualAfterUnpack(_logFile, replayedLogFile); + } + + private static void AssertFilesAreBinaryEqualAfterUnpack(string firstPath, string secondPath) + { + using var br1 = BinaryLogReplayEventSource.OpenReader(firstPath); + using var br2 = BinaryLogReplayEventSource.OpenReader(secondPath); + const int bufferSize = 4096; + + int readCount = 0; + while (br1.ReadBytes(bufferSize) is { Length: > 0 } bytes1) + { + var bytes2 = br2.ReadBytes(bufferSize); + + bytes1.SequenceEqual(bytes2).ShouldBeTrue( + $"Buffers starting at position {readCount} differ. First:{Environment.NewLine}{string.Join(",", bytes1)}{Environment.NewLine}Second:{Environment.NewLine}{string.Join(",", bytes2)}"); + readCount += bufferSize; + } + + br2.ReadBytes(bufferSize).Length.ShouldBe(0, "Second buffer contains bytes after first file end"); + } + + private static void AssertBinlogsHaveEqualContent(string firstPath, string secondPath) + { + using var reader1 = BinaryLogReplayEventSource.OpenBuildEventsReader(firstPath); + using var reader2 = BinaryLogReplayEventSource.OpenBuildEventsReader(secondPath); + + Dictionary embedFiles1 = new(); + Dictionary embedFiles2 = new(); + + reader1.ArchiveFileEncountered += arg + => AddArchiveFile(embedFiles1, arg); + + // This would be standard subscribe: + // reader2.ArchiveFileEncountered += arg + // => AddArchiveFile(embedFiles2, arg); + + // We however use the AddArchiveFileFromStringHandler - to exercise it + // and to assert it's equality with ArchiveFileEncountered handler + string currentFileName = null; + reader2.ArchiveFileEncountered += + ((Action)AddArchiveFileFromStringHandler).ToArchiveFileHandler(); + + int i = 0; + while (reader1.Read() is { } ev1) + { + i++; + var ev2 = reader2.Read(); + + ev1.Should().BeEquivalentTo(ev2, + $"Binlogs ({firstPath} and {secondPath}) should be equal at event {i}"); + } + // Read the second reader - to confirm there are no more events + // and to force the embedded files to be read. + reader2.Read().ShouldBeNull($"Binlogs ({firstPath} and {secondPath}) are not equal - second has more events >{i + 1}"); + + Assert.Equal(embedFiles1, embedFiles2); + + void AddArchiveFile(Dictionary files, ArchiveFileEventArgs arg) + { + ArchiveFile embedFile = arg.ArchiveData.ToArchiveFile(); + files.Add(embedFile.FullPath, embedFile.Content); + } + + void AddArchiveFileFromStringHandler(StringReadEventArgs args) + { + if (currentFileName == null) + { + currentFileName = args.OriginalString; + return; + } + + embedFiles2.Add(currentFileName, args.OriginalString); + currentFileName = null; + } + } + [Fact] public void BinaryLoggerShouldSupportFilePathExplicitParameter() { diff --git a/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs b/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs index faacc88379f..99474115048 100644 --- a/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs +++ b/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs @@ -7,6 +7,7 @@ using System.IO; using System.Linq; using System.Text; +using FluentAssertions; using Microsoft.Build.BackEnd; using Microsoft.Build.Framework; using Microsoft.Build.Framework.Profiler; @@ -894,6 +895,232 @@ public void ReadingCorruptedStreamThrows() } } + [Fact] + public void ForwardCompatibleRead_HandleAppendOnlyChanges() + { + // Let's not write any strings prior the first event - to make locating (and overwriting) the size byte(s) easier. + BuildErrorEventArgs error = new(null, null, null, 1, 2, 3, 4, null, null, null); + BuildFinishedEventArgs finished = new("Message", "HelpKeyword", true); + + var memoryStream = new MemoryStream(); + var binaryWriter = new BinaryWriter(memoryStream); + var binaryReader = new BinaryReader(memoryStream); + var buildEventArgsWriter = new BuildEventArgsWriter(binaryWriter); + + buildEventArgsWriter.Write(error); + + // Some future data that are not known in current version + binaryWriter.Write(new byte[] { 1, 2, 3, 4 }); + + + int positionAfterFirstEvent = (int)memoryStream.Position; + memoryStream.Position = 0; + // event type + Microsoft.Build.Shared.BinaryReaderExtensions.Read7BitEncodedInt(binaryReader); + int eventSizePos = (int)memoryStream.Position; + int eventSize = Microsoft.Build.Shared.BinaryReaderExtensions.Read7BitEncodedInt(binaryReader); + int positionAfterFirstEventSize = (int)memoryStream.Position; + memoryStream.Position = eventSizePos; + // the extra 4 bytes + Microsoft.Build.Shared.BinaryWriterExtensions.Write7BitEncodedInt(binaryWriter, eventSize + 4); + memoryStream.Position.ShouldBe(positionAfterFirstEventSize, "The event size need to be overwritten in place - without overwriting any bytes after the size info"); + memoryStream.Position = positionAfterFirstEvent; + + buildEventArgsWriter.Write(finished); + + // Remember num of bytes written - we should read them all. + long length = memoryStream.Length; + // Now move back to the beginning of the stream and start reading. + memoryStream.Position = 0; + + using var buildEventArgsReader = new BuildEventArgsReader(binaryReader, BinaryLogger.FileFormatVersion) + { + SkipUnknownEventParts = true + }; + + List readerErrors = new(); + buildEventArgsReader.RecoverableReadError += readerErrors.Add; + + var deserializedError = (BuildErrorEventArgs)buildEventArgsReader.Read(); + + readerErrors.Count.ShouldBe(1); + readerErrors[0].ErrorType.ShouldBe(ReaderErrorType.UnknownEventData); + readerErrors[0].RecordKind.ShouldBe(BinaryLogRecordKind.Error); + + deserializedError.Should().BeEquivalentTo(error); + + var deserializedFinished = (BuildFinishedEventArgs)buildEventArgsReader.Read(); + + readerErrors.Count.ShouldBe(1); + + deserializedFinished.Should().BeEquivalentTo(finished); + + // There is nothing else in the stream + memoryStream.Position.Should().Be(length); + } + + [Fact] + public void ForwardCompatibleRead_HandleUnknownEvent() + { + // Let's not write any strings prior the first event - to make locating (and overwriting) the event type byte(s) easier. + BuildErrorEventArgs error = new(null, null, null, 1, 2, 3, 4, null, null, null); + BuildFinishedEventArgs finished = new("Message", "HelpKeyword", true); + + var memoryStream = new MemoryStream(); + var binaryWriter = new BinaryWriter(memoryStream); + var binaryReader = new BinaryReader(memoryStream); + var buildEventArgsWriter = new BuildEventArgsWriter(binaryWriter); + + buildEventArgsWriter.Write(error); + + int positionAfterFirstEvent = (int)memoryStream.Position; + memoryStream.Position = 0; + // event type + Microsoft.Build.Shared.BinaryReaderExtensions.Read7BitEncodedInt(binaryReader); + int eventSizePos = (int)memoryStream.Position; + memoryStream.Position = 0; + + // some future type that is not known in current version + BinaryLogRecordKind unknownType = (BinaryLogRecordKind) Enum.GetValues(typeof(BinaryLogRecordKind)).Cast().Select(e => (int)e).Max() + 2; + Microsoft.Build.Shared.BinaryWriterExtensions.Write7BitEncodedInt(binaryWriter, (int)unknownType); + memoryStream.Position.ShouldBe(eventSizePos, "The event type need to be overwritten in place - without overwriting any bytes after the type info"); + memoryStream.Position = positionAfterFirstEvent; + + buildEventArgsWriter.Write(finished); + + // Remember num of bytes written - we should read them all. + long length = memoryStream.Length; + // Now move back to the beginning of the stream and start reading. + memoryStream.Position = 0; + + List readerErrors = new(); + using var buildEventArgsReader = new BuildEventArgsReader(binaryReader, BinaryLogger.FileFormatVersion) + { + SkipUnknownEvents = true + }; + + buildEventArgsReader.RecoverableReadError += readerErrors.Add; + + var deserializedEvent = buildEventArgsReader.Read(); + + readerErrors.Count.ShouldBe(1); + readerErrors[0].ErrorType.ShouldBe(ReaderErrorType.UnknownEventType); + readerErrors[0].RecordKind.ShouldBe(unknownType); + + deserializedEvent.Should().BeEquivalentTo(finished); + + // There is nothing else in the stream + memoryStream.Position.Should().Be(length); + } + + [Fact] + public void ForwardCompatibleRead_HandleMismatchedFormatOfEvent() + { + // BuildErrorEventArgs error = new("Subcategory", "Code", "File", 1, 2, 3, 4, "Message", "HelpKeyword", "SenderName"); + BuildErrorEventArgs error = new(null, null, null, 1, 2, 3, 4, null, null, null); + BuildFinishedEventArgs finished = new("Message", "HelpKeyword", true); + + var memoryStream = new MemoryStream(); + var binaryWriter = new BinaryWriter(memoryStream); + var binaryReader = new BinaryReader(memoryStream); + var buildEventArgsWriter = new BuildEventArgsWriter(binaryWriter); + + buildEventArgsWriter.Write(error); + + int positionAfterFirstEvent = (int)memoryStream.Position; + memoryStream.Position = 0; + // event type + Microsoft.Build.Shared.BinaryReaderExtensions.Read7BitEncodedInt(binaryReader); + int eventSize = Microsoft.Build.Shared.BinaryReaderExtensions.Read7BitEncodedInt(binaryReader); + // overwrite the entire event with garbage + binaryWriter.Write(Enumerable.Repeat(byte.MaxValue, eventSize).ToArray()); + + memoryStream.Position.ShouldBe(positionAfterFirstEvent, "The event need to be overwritten in place - without overwriting any bytes after the size info"); + + buildEventArgsWriter.Write(finished); + + // Remember num of bytes written - we should read them all. + long length = memoryStream.Length; + // Now move back to the beginning of the stream and start reading. + memoryStream.Position = 0; + + using var buildEventArgsReader = new BuildEventArgsReader(binaryReader, BinaryLogger.FileFormatVersion) + { + SkipUnknownEvents = true + }; + + List readerErrors = new(); + buildEventArgsReader.RecoverableReadError += readerErrors.Add; + + var deserializedEvent = buildEventArgsReader.Read(); + + readerErrors.Count.ShouldBe(1); + readerErrors[0].ErrorType.ShouldBe(ReaderErrorType.UnknownFormatOfEventData); + readerErrors[0].RecordKind.ShouldBe(BinaryLogRecordKind.Error); + readerErrors[0].GetFormattedMessage().ShouldContain("FormatException"); + + deserializedEvent.Should().BeEquivalentTo(finished); + + // There is nothing else in the stream + memoryStream.Position.Should().Be(length); + } + + [Fact] + public void ForwardCompatibleRead_HandleRemovalOfDataFromEventDefinition() + { + // BuildErrorEventArgs error = new("Subcategory", "Code", "File", 1, 2, 3, 4, "Message", "HelpKeyword", "SenderName"); + BuildErrorEventArgs error = new(null, null, null, 1, 2, 3, 4, null, null, null); + BuildFinishedEventArgs finished = new("Message", "HelpKeyword", true); + + var memoryStream = new MemoryStream(); + var binaryWriter = new BinaryWriter(memoryStream); + var binaryReader = new BinaryReader(memoryStream); + var buildEventArgsWriter = new BuildEventArgsWriter(binaryWriter); + + buildEventArgsWriter.Write(error); + + int positionAfterFirstEvent = (int)memoryStream.Position; + memoryStream.Position = 0; + // event type + Microsoft.Build.Shared.BinaryReaderExtensions.Read7BitEncodedInt(binaryReader); + int eventSizePos = (int)memoryStream.Position; + int eventSize = Microsoft.Build.Shared.BinaryReaderExtensions.Read7BitEncodedInt(binaryReader); + int positionAfterFirstEventSize = (int)memoryStream.Position; + memoryStream.Position = eventSizePos; + // simulate there are 4 bytes less in the future version of the event - while our reader expects those + Microsoft.Build.Shared.BinaryWriterExtensions.Write7BitEncodedInt(binaryWriter, eventSize - 4); + memoryStream.Position.ShouldBe(positionAfterFirstEventSize, "The event size need to be overwritten in place - without overwriting any bytes after the size info"); + // remove the 4 bytes - so that actual size of event is inline with it's written size. + memoryStream.Position = positionAfterFirstEvent - 4; + + buildEventArgsWriter.Write(finished); + + // Remember num of bytes written - we should read them all. + long length = memoryStream.Length; + // Now move back to the beginning of the stream and start reading. + memoryStream.Position = 0; + + using var buildEventArgsReader = new BuildEventArgsReader(binaryReader, BinaryLogger.FileFormatVersion) + { + SkipUnknownEvents = true + }; + + List readerErrors = new(); + buildEventArgsReader.RecoverableReadError += readerErrors.Add; + + var deserializedEvent = buildEventArgsReader.Read(); + + readerErrors.Count.ShouldBe(1); + readerErrors[0].ErrorType.ShouldBe(ReaderErrorType.UnknownFormatOfEventData); + readerErrors[0].RecordKind.ShouldBe(BinaryLogRecordKind.Error); + readerErrors[0].GetFormattedMessage().ShouldContain("EndOfStreamException"); + + deserializedEvent.Should().BeEquivalentTo(finished); + + // There is nothing else in the stream + memoryStream.Position.Should().Be(length); + } + private string ToString(BuildEventContext context) { return $"{context.BuildRequestId} {context.NodeId} {context.ProjectContextId} {context.ProjectInstanceId} {context.SubmissionId} {context.TargetId} {context.TaskId}"; diff --git a/src/Build/CompatibilitySuppressions.xml b/src/Build/CompatibilitySuppressions.xml new file mode 100644 index 00000000000..8497df99fb3 --- /dev/null +++ b/src/Build/CompatibilitySuppressions.xml @@ -0,0 +1,263 @@ + + + + + CP0001 + T:Microsoft.Build.Logging.IBuildEventStringsReader + lib/net472/Microsoft.Build.dll + lib/net472/Microsoft.Build.dll + true + + + CP0001 + T:Microsoft.Build.Logging.IBuildEventStringsReader + lib/net8.0/Microsoft.Build.dll + lib/net8.0/Microsoft.Build.dll + true + + + CP0001 + T:Microsoft.Build.Logging.IBuildEventStringsReader + ref/net472/Microsoft.Build.dll + ref/net472/Microsoft.Build.dll + true + + + CP0001 + T:Microsoft.Build.Logging.IBuildEventStringsReader + ref/net8.0/Microsoft.Build.dll + ref/net8.0/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BinaryLogReplayEventSource.add_NotificationsSourceCreated(System.Action{Microsoft.Build.Logging.IBuildEventArgsReaderNotifications}) + lib/net472/Microsoft.Build.dll + lib/net472/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BinaryLogReplayEventSource.remove_NotificationsSourceCreated(System.Action{Microsoft.Build.Logging.IBuildEventArgsReaderNotifications}) + lib/net472/Microsoft.Build.dll + lib/net472/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BuildEventArgsReader.add_StringEncountered(System.Action) + lib/net472/Microsoft.Build.dll + lib/net472/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BuildEventArgsReader.remove_StringEncountered(System.Action) + lib/net472/Microsoft.Build.dll + lib/net472/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BinaryLogReplayEventSource.add_NotificationsSourceCreated(System.Action{Microsoft.Build.Logging.IBuildEventArgsReaderNotifications}) + lib/net8.0/Microsoft.Build.dll + lib/net8.0/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BinaryLogReplayEventSource.remove_NotificationsSourceCreated(System.Action{Microsoft.Build.Logging.IBuildEventArgsReaderNotifications}) + lib/net8.0/Microsoft.Build.dll + lib/net8.0/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BuildEventArgsReader.add_StringEncountered(System.Action) + lib/net8.0/Microsoft.Build.dll + lib/net8.0/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BuildEventArgsReader.remove_StringEncountered(System.Action) + lib/net8.0/Microsoft.Build.dll + lib/net8.0/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BinaryLogReplayEventSource.add_NotificationsSourceCreated(System.Action{Microsoft.Build.Logging.IBuildEventArgsReaderNotifications}) + ref/net472/Microsoft.Build.dll + ref/net472/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BinaryLogReplayEventSource.remove_NotificationsSourceCreated(System.Action{Microsoft.Build.Logging.IBuildEventArgsReaderNotifications}) + ref/net472/Microsoft.Build.dll + ref/net472/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BuildEventArgsReader.add_StringEncountered(System.Action) + ref/net472/Microsoft.Build.dll + ref/net472/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BuildEventArgsReader.remove_StringEncountered(System.Action) + ref/net472/Microsoft.Build.dll + ref/net472/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BinaryLogReplayEventSource.add_NotificationsSourceCreated(System.Action{Microsoft.Build.Logging.IBuildEventArgsReaderNotifications}) + ref/net8.0/Microsoft.Build.dll + ref/net8.0/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BinaryLogReplayEventSource.remove_NotificationsSourceCreated(System.Action{Microsoft.Build.Logging.IBuildEventArgsReaderNotifications}) + ref/net8.0/Microsoft.Build.dll + ref/net8.0/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BuildEventArgsReader.add_StringEncountered(System.Action) + ref/net8.0/Microsoft.Build.dll + ref/net8.0/Microsoft.Build.dll + true + + + CP0002 + M:Microsoft.Build.Logging.BuildEventArgsReader.remove_StringEncountered(System.Action) + ref/net8.0/Microsoft.Build.dll + ref/net8.0/Microsoft.Build.dll + true + + + CP0006 + E:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications.ArchiveFileEncountered + lib/net472/Microsoft.Build.dll + lib/net472/Microsoft.Build.dll + true + + + CP0006 + E:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications.RecoverableReadError + lib/net472/Microsoft.Build.dll + lib/net472/Microsoft.Build.dll + true + + + CP0006 + E:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications.StringReadDone + lib/net472/Microsoft.Build.dll + lib/net472/Microsoft.Build.dll + true + + + CP0006 + E:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications.ArchiveFileEncountered + lib/net8.0/Microsoft.Build.dll + lib/net8.0/Microsoft.Build.dll + true + + + CP0006 + E:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications.RecoverableReadError + lib/net8.0/Microsoft.Build.dll + lib/net8.0/Microsoft.Build.dll + true + + + CP0006 + E:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications.StringReadDone + lib/net8.0/Microsoft.Build.dll + lib/net8.0/Microsoft.Build.dll + true + + + CP0006 + E:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications.ArchiveFileEncountered + ref/net8.0/Microsoft.Build.dll + ref/net8.0/Microsoft.Build.dll + true + + + CP0006 + E:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications.RecoverableReadError + ref/net8.0/Microsoft.Build.dll + ref/net8.0/Microsoft.Build.dll + true + + + CP0006 + E:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications.StringReadDone + ref/net8.0/Microsoft.Build.dll + ref/net8.0/Microsoft.Build.dll + true + + + CP0008 + T:Microsoft.Build.Logging.BuildEventArgsReader + lib/net472/Microsoft.Build.dll + lib/net472/Microsoft.Build.dll + true + + + CP0008 + T:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications + lib/net472/Microsoft.Build.dll + lib/net472/Microsoft.Build.dll + true + + + CP0008 + T:Microsoft.Build.Logging.BuildEventArgsReader + lib/net8.0/Microsoft.Build.dll + lib/net8.0/Microsoft.Build.dll + true + + + CP0008 + T:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications + lib/net8.0/Microsoft.Build.dll + lib/net8.0/Microsoft.Build.dll + true + + + CP0008 + T:Microsoft.Build.Logging.BuildEventArgsReader + ref/net472/Microsoft.Build.dll + ref/net472/Microsoft.Build.dll + true + + + CP0008 + T:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications + ref/net472/Microsoft.Build.dll + ref/net472/Microsoft.Build.dll + true + + + CP0008 + T:Microsoft.Build.Logging.BuildEventArgsReader + ref/net8.0/Microsoft.Build.dll + ref/net8.0/Microsoft.Build.dll + true + + + CP0008 + T:Microsoft.Build.Logging.IBuildEventArgsReaderNotifications + ref/net8.0/Microsoft.Build.dll + ref/net8.0/Microsoft.Build.dll + true + + \ No newline at end of file diff --git a/src/Build/Logging/BinaryLogger/BinaryLogRecordKind.cs b/src/Build/Logging/BinaryLogger/BinaryLogRecordKind.cs index 9fe1638fd3a..22921695dea 100644 --- a/src/Build/Logging/BinaryLogger/BinaryLogRecordKind.cs +++ b/src/Build/Logging/BinaryLogger/BinaryLogRecordKind.cs @@ -5,7 +5,12 @@ namespace Microsoft.Build.Logging { - internal enum BinaryLogRecordKind + /// + /// Indicates the type of record stored in the binary log. + /// There is a record type for each type of build event and there + /// are also few meta-data record types (e.g. string data, lookup data, EOF). + /// + public enum BinaryLogRecordKind { EndOfFile = 0, BuildStarted, diff --git a/src/Build/Logging/BinaryLogger/BinaryLogReplayEventSource.cs b/src/Build/Logging/BinaryLogger/BinaryLogReplayEventSource.cs index a19a06c2d37..abf9e4e80c9 100644 --- a/src/Build/Logging/BinaryLogger/BinaryLogReplayEventSource.cs +++ b/src/Build/Logging/BinaryLogger/BinaryLogReplayEventSource.cs @@ -11,13 +11,63 @@ namespace Microsoft.Build.Logging { + /// + /// Interface for replaying a binary log file (*.binlog) + /// + internal interface IBinaryLogReplaySource : + IEventSource, + IBuildEventArgsReaderNotifications + { + /// + /// Event raised when non-textual log record is read. + /// This means all event args and key-value pairs. + /// Strings and Embedded files are not included. + /// + event Action? RawLogRecordReceived; + + /// + /// Enables initialization (e.g. subscription to events) - that is deferred until Replay is triggered. + /// At this point all other possible subscribers should be already subscribed - + /// so it can be determined if raw events or structured events should be replayed. + /// + /// + /// + void DeferredInitialize( + Action onRawReadingPossible, + Action onStructuredReadingOnly); + + /// + /// File format version of the binary log file. + /// + int FileFormatVersion { get; } + + /// + /// The minimum reader version for the binary log file. + /// + int MinimumReaderVersion { get; } + + /// + /// Raised when the log reader encounters a project import archive (embedded content) in the stream. + /// The subscriber must read the exactly given length of binary data from the stream - otherwise exception is raised. + /// If no subscriber is attached, the data is skipped. + /// + event Action EmbeddedContentRead; + } + /// /// Provides a method to read a binary log file (*.binlog) and replay all stored BuildEventArgs /// by implementing IEventSource and raising corresponding events. /// /// The class is public so that we can call it from MSBuild.exe when replaying a log file. - public sealed class BinaryLogReplayEventSource : EventArgsDispatcher + public sealed class BinaryLogReplayEventSource : EventArgsDispatcher, + IBinaryLogReplaySource { + private int? _fileFormatVersion; + private int? _minimumReaderVersion; + + public int FileFormatVersion => _fileFormatVersion ?? throw new InvalidOperationException(ResourceUtilities.GetResourceString("Binlog_Source_VersionUninitialized")); + public int MinimumReaderVersion => _minimumReaderVersion ?? throw new InvalidOperationException(ResourceUtilities.GetResourceString("Binlog_Source_VersionUninitialized")); + /// Touches the static constructor /// to ensure it initializes /// and @@ -27,9 +77,12 @@ static BinaryLogReplayEventSource() } /// - /// Raised once is created during replaying + /// Unknown build events or unknown parts of known build events will be ignored if this is set to true. /// - public event Action? NotificationsSourceCreated; + public bool AllowForwardCompatibility { private get; init; } + + /// + public event Action? RecoverableReadError; /// /// Read the provided binary log file and raise corresponding events for each BuildEventArgs @@ -40,6 +93,17 @@ public void Replay(string sourceFilePath) Replay(sourceFilePath, CancellationToken.None); } + /// + /// Read the provided binary log file opened as a stream and raise corresponding events for each BuildEventArgs + /// + /// Stream over the binlog content. + /// + public void Replay(Stream sourceFileStream, CancellationToken cancellationToken) + { + using var binaryReader = OpenReader(sourceFileStream); + Replay(binaryReader, cancellationToken); + } + /// /// Creates a for the provided binary log file. /// Performs decompression and buffering in the optimal way. @@ -53,21 +117,78 @@ public static BinaryReader OpenReader(string sourceFilePath) try { stream = new FileStream(sourceFilePath, FileMode.Open, FileAccess.Read, FileShare.Read); - var gzipStream = new GZipStream(stream, CompressionMode.Decompress, leaveOpen: false); - - // wrapping the GZipStream in a buffered stream significantly improves performance - // and the max throughput is reached with a 32K buffer. See details here: - // https://github.com/dotnet/runtime/issues/39233#issuecomment-745598847 - var bufferedStream = new BufferedStream(gzipStream, 32768); - return new BinaryReader(bufferedStream); + return OpenReader(stream); } - catch(Exception) + catch (Exception) { stream?.Dispose(); throw; } } + /// + /// Creates a for the provided binary log file. + /// Performs decompression and buffering in the optimal way. + /// Caller is responsible for disposing the returned reader. + /// + /// Stream over the binlog file + /// BinaryReader of the given binlog file. + public static BinaryReader OpenReader(Stream sourceFileStream) + { + var gzipStream = new GZipStream(sourceFileStream, CompressionMode.Decompress, leaveOpen: false); + + // wrapping the GZipStream in a buffered stream significantly improves performance + // and the max throughput is reached with a 32K buffer. See details here: + // https://github.com/dotnet/runtime/issues/39233#issuecomment-745598847 + var bufferedStream = new BufferedStream(gzipStream, 32768); + return new BinaryReader(bufferedStream); + } + + /// + /// Creates a for the provided binary reader over binary log file. + /// Caller is responsible for disposing the returned reader. + /// + /// + /// Indicates whether the passed BinaryReader should be closed on disposing. + /// Unknown build events or unknown parts of known build events will be ignored if this is set to true. + /// BuildEventArgsReader over the given binlog file binary reader. + public static BuildEventArgsReader OpenBuildEventsReader( + BinaryReader binaryReader, + bool closeInput, + bool allowForwardCompatibility = false) + { + int fileFormatVersion = binaryReader.ReadInt32(); + // Is this the new log format that contains the minimum reader version? + int minimumReaderVersion = fileFormatVersion >= BinaryLogger.ForwardCompatibilityMinimalVersion + ? binaryReader.ReadInt32() + : fileFormatVersion; + + // the log file is written using a newer version of file format + // that we don't know how to read + if (fileFormatVersion > BinaryLogger.FileFormatVersion && + (!allowForwardCompatibility || minimumReaderVersion > BinaryLogger.FileFormatVersion)) + { + var text = ResourceUtilities.FormatResourceStringStripCodeAndKeyword("UnsupportedLogFileFormat", fileFormatVersion, minimumReaderVersion, BinaryLogger.FileFormatVersion); + throw new NotSupportedException(text); + } + + return new BuildEventArgsReader(binaryReader, fileFormatVersion) + { + CloseInput = closeInput, + MinimumReaderVersion = minimumReaderVersion + }; + } + + /// + /// Creates a for the provided binary log file. + /// Performs decompression and buffering in the optimal way. + /// Caller is responsible for disposing the returned reader. + /// + /// + /// BinaryReader of the given binlog file. + public static BuildEventArgsReader OpenBuildEventsReader(string sourceFilePath) + => OpenBuildEventsReader(OpenReader(sourceFilePath), true); + /// /// Read the provided binary log file and raise corresponding events for each BuildEventArgs /// @@ -75,8 +196,8 @@ public static BinaryReader OpenReader(string sourceFilePath) /// A indicating the replay should stop as soon as possible. public void Replay(string sourceFilePath, CancellationToken cancellationToken) { - using var binaryReader = OpenReader(sourceFilePath); - Replay(binaryReader, cancellationToken); + using var eventsReader = OpenBuildEventsReader(sourceFilePath); + Replay(eventsReader, cancellationToken); } /// @@ -85,24 +206,137 @@ public void Replay(string sourceFilePath, CancellationToken cancellationToken) /// The binary log content binary reader - caller is responsible for disposing. /// A indicating the replay should stop as soon as possible. public void Replay(BinaryReader binaryReader, CancellationToken cancellationToken) + => Replay(binaryReader, false, cancellationToken); + + /// + /// Read the provided binary log file and raise corresponding events for each BuildEventArgs + /// + /// The binary log content binary reader - caller is responsible for disposing, unless is set to true. + /// Indicates whether the passed BinaryReader should be closed on disposing. + /// A indicating the replay should stop as soon as possible. + public void Replay(BinaryReader binaryReader, bool closeInput, CancellationToken cancellationToken) { - int fileFormatVersion = binaryReader.ReadInt32(); + using var reader = OpenBuildEventsReader(binaryReader, closeInput, AllowForwardCompatibility); + Replay(reader, cancellationToken); + } - // the log file is written using a newer version of file format - // that we don't know how to read - if (fileFormatVersion > BinaryLogger.FileFormatVersion) + /// + /// Read the provided binary log file and raise corresponding events for each BuildEventArgs + /// + /// The build events reader - caller is responsible for disposing. + /// A indicating the replay should stop as soon as possible. + public void Replay(BuildEventArgsReader reader, CancellationToken cancellationToken) + { + _fileFormatVersion = reader.FileFormatVersion; + _minimumReaderVersion = reader.MinimumReaderVersion; + bool supportsForwardCompatibility = reader.FileFormatVersion >= BinaryLogger.ForwardCompatibilityMinimalVersion; + + // Allow any possible deferred subscriptions to be registered + if (HasStructuredEventsSubscribers || !supportsForwardCompatibility) { - var text = ResourceUtilities.FormatResourceStringStripCodeAndKeyword("UnsupportedLogFileFormat", fileFormatVersion, BinaryLogger.FileFormatVersion); - throw new NotSupportedException(text); + _onStructuredReadingOnly?.Invoke(); + } + else + { + _onRawReadingPossible?.Invoke(); } - using var reader = new BuildEventArgsReader(binaryReader, fileFormatVersion); - NotificationsSourceCreated?.Invoke(reader); + reader.EmbeddedContentRead += _embeddedContentRead; + reader.ArchiveFileEncountered += _archiveFileEncountered; + reader.StringReadDone += _stringReadDone; - while (!cancellationToken.IsCancellationRequested && reader.Read() is { } instance) + if (HasStructuredEventsSubscribers || !supportsForwardCompatibility) { - Dispatch(instance); + if (this._rawLogRecordReceived != null) + { + throw new NotSupportedException( + ResourceUtilities.GetResourceString("Binlog_Source_MultiSubscribeError")); + } + + // Forward compatible reading makes sense only for structured events reading. + reader.SkipUnknownEvents = supportsForwardCompatibility && AllowForwardCompatibility; + reader.SkipUnknownEventParts = supportsForwardCompatibility && AllowForwardCompatibility; + reader.RecoverableReadError += RecoverableReadError; + + while (!cancellationToken.IsCancellationRequested && reader.Read() is { } instance) + { + Dispatch(instance); + } } + else + { + if (this._rawLogRecordReceived == null && + this._embeddedContentRead == null && + this._stringReadDone == null && + this._archiveFileEncountered == null) + { + throw new NotSupportedException( + ResourceUtilities.GetResourceString("Binlog_Source_MissingSubscribeError")); + } + + while (!cancellationToken.IsCancellationRequested && reader.ReadRaw() is { } instance && + instance.RecordKind != BinaryLogRecordKind.EndOfFile) + { + _rawLogRecordReceived?.Invoke(instance.RecordKind, instance.Stream); + } + } + + // Unsubscribe from events for a case if the reader is reused (upon cancellation). + reader.EmbeddedContentRead -= _embeddedContentRead; + reader.ArchiveFileEncountered -= _archiveFileEncountered; + reader.StringReadDone -= _stringReadDone; + reader.RecoverableReadError -= RecoverableReadError; + } + + // Following members are explicit implementations of the IBinaryLogReplaySource interface + // to avoid exposing them publicly. + // We want an interface so that BinaryLogger can fine tune its initialization logic + // in case the given event source is the replay source. On the other hand we don't want + // to expose these members publicly because they are not intended to be used by the consumers. + + private Action? _onRawReadingPossible; + private Action? _onStructuredReadingOnly; + /// + void IBinaryLogReplaySource.DeferredInitialize( + Action onRawReadingPossible, + Action onStructuredReadingOnly) + { + this._onRawReadingPossible += onRawReadingPossible; + this._onStructuredReadingOnly += onStructuredReadingOnly; + } + + private Action? _embeddedContentRead; + /// + event Action? IBinaryLogReplaySource.EmbeddedContentRead + { + // Explicitly implemented event has to declare explicit add/remove accessors + // https://stackoverflow.com/a/2268472/2308106 + add => _embeddedContentRead += value; + remove => _embeddedContentRead -= value; + } + + private Action? _stringReadDone; + /// + event Action? IBuildEventArgsReaderNotifications.StringReadDone + { + add => _stringReadDone += value; + remove => _stringReadDone -= value; + } + + private Action? _archiveFileEncountered; + /// + event Action? IBuildEventArgsReaderNotifications.ArchiveFileEncountered + { + add => _archiveFileEncountered += value; + remove => _archiveFileEncountered -= value; + } + + private Action? _rawLogRecordReceived; + /// + event Action? IBinaryLogReplaySource.RawLogRecordReceived + { + add => _rawLogRecordReceived += value; + remove => _rawLogRecordReceived -= value; } } } diff --git a/src/Build/Logging/BinaryLogger/BinaryLogger.cs b/src/Build/Logging/BinaryLogger/BinaryLogger.cs index a935708e681..a9e6f75705f 100644 --- a/src/Build/Logging/BinaryLogger/BinaryLogger.cs +++ b/src/Build/Logging/BinaryLogger/BinaryLogger.cs @@ -63,7 +63,24 @@ public sealed class BinaryLogger : ILogger // - AssemblyLoadBuildEventArgs // version 17: // - Added extended data for types implementing IExtendedBuildEventArgs - internal const int FileFormatVersion = 17; + // version 18: + // - Making ProjectStartedEventArgs, ProjectEvaluationFinishedEventArgs, AssemblyLoadBuildEventArgs equal + // between de/serialization roundtrips. + // - Adding serialized events lengths - to support forward compatible reading + + // This should be never changed. + // The minimum version of the binary log reader that can read log of above version. + internal const int ForwardCompatibilityMinimalVersion = 18; + + // The current version of the binary log representation. + // Changes with each update of the binary log format. + internal const int FileFormatVersion = 18; + + // The minimum version of the binary log reader that can read log of above version. + // This should be changed only when the binary log format is changed in a way that would prevent it from being + // read by older readers. (changing of the individual BuildEventArgs or adding new is fine - as reader can + // skip them if they are not known to it. Example of change requiring the increment would be the introduction of strings deduplication) + internal const int MinimumReaderVersion = 18; private Stream stream; private BinaryWriter binaryWriter; @@ -92,7 +109,7 @@ public enum ProjectImportsCollectionMode /// /// Create an external .ProjectImports.zip archive for the project files. /// - ZipFile + ZipFile, } /// @@ -115,7 +132,7 @@ public enum ProjectImportsCollectionMode public string Parameters { get; set; } /// - /// Initializes the logger by subscribing to events of the specified event source. + /// Initializes the logger by subscribing to events of the specified event source and embedded content source. /// public void Initialize(IEventSource eventSource) { @@ -130,7 +147,8 @@ public void Initialize(IEventSource eventSource) Traits.Instance.EscapeHatches.LogProjectImports = true; bool logPropertiesAndItemsAfterEvaluation = Traits.Instance.EscapeHatches.LogPropertiesAndItemsAfterEvaluation ?? true; - ProcessParameters(); + ProcessParameters(out bool omitInitialInfo); + var replayEventSource = eventSource as IBinaryLogReplaySource; try { @@ -152,7 +170,7 @@ public void Initialize(IEventSource eventSource) stream = new FileStream(FilePath, FileMode.Create); - if (CollectProjectImports != ProjectImportsCollectionMode.None) + if (CollectProjectImports != ProjectImportsCollectionMode.None && replayEventSource == null) { projectImportsCollector = new ProjectImportsCollector(FilePath, CollectProjectImports == ProjectImportsCollectionMode.ZipFile); } @@ -189,13 +207,57 @@ public void Initialize(IEventSource eventSource) eventArgsWriter.EmbedFile += EventArgsWriter_EmbedFile; } - binaryWriter.Write(FileFormatVersion); - - LogInitialInfo(); + if (replayEventSource != null) + { + if (CollectProjectImports == ProjectImportsCollectionMode.Embed) + { + replayEventSource.EmbeddedContentRead += args => + eventArgsWriter.WriteBlob(args.ContentKind, args.ContentStream); + } + else if (CollectProjectImports == ProjectImportsCollectionMode.ZipFile) + { + replayEventSource.EmbeddedContentRead += args => + ProjectImportsCollector.FlushBlobToFile(FilePath, args.ContentStream); + } - eventSource.AnyEventRaised += EventSource_AnyEventRaised; + // If raw events are provided - let's try to use the advantage. + // But other subscribers can later on subscribe to structured events - + // for this reason we do only subscribe delayed. + replayEventSource.DeferredInitialize( + // For raw events we cannot write the initial info - as we cannot write + // at the same time as raw events are being written - this would break the deduplicated strings store. + // But we need to write the version info - but since we read/write raw - let's not change the version info. + () => + { + binaryWriter.Write(replayEventSource.FileFormatVersion); + binaryWriter.Write(replayEventSource.MinimumReaderVersion); + replayEventSource.RawLogRecordReceived += RawEvents_LogDataSliceReceived; + // Replay separated strings here as well (and do not deduplicate! It would skew string indexes) + replayEventSource.StringReadDone += strArg => eventArgsWriter.WriteStringRecord(strArg.StringToBeUsed); + }, + SubscribeToStructuredEvents); + } + else + { + SubscribeToStructuredEvents(); + } KnownTelemetry.LoggingConfigurationTelemetry.BinaryLogger = true; + + void SubscribeToStructuredEvents() + { + // Write the version info - the latest version is written only for structured events replaying + // as raw events do not change structure - hence the version is the same as the one they were written with. + binaryWriter.Write(FileFormatVersion); + binaryWriter.Write(MinimumReaderVersion); + + if (!omitInitialInfo) + { + LogInitialInfo(); + } + + eventSource.AnyEventRaised += EventSource_AnyEventRaised; + } } private void EventArgsWriter_EmbedFile(string filePath) @@ -236,26 +298,11 @@ public void Shutdown() if (CollectProjectImports == ProjectImportsCollectionMode.Embed) { - var archiveFilePath = projectImportsCollector.ArchiveFilePath; + projectImportsCollector.ProcessResult( + streamToEmbed => eventArgsWriter.WriteBlob(BinaryLogRecordKind.ProjectImportArchive, streamToEmbed), + LogMessage); - // It is possible that the archive couldn't be created for some reason. - // Only embed it if it actually exists. - if (FileSystems.Default.FileExists(archiveFilePath)) - { - using (FileStream fileStream = File.OpenRead(archiveFilePath)) - { - if (fileStream.Length > int.MaxValue) - { - LogMessage("Imported files archive exceeded 2GB limit and it's not embedded."); - } - else - { - eventArgsWriter.WriteBlob(BinaryLogRecordKind.ProjectImportArchive, fileStream); - } - } - - File.Delete(archiveFilePath); - } + projectImportsCollector.DeleteArchive(); } projectImportsCollector = null; @@ -272,6 +319,11 @@ public void Shutdown() } } + private void RawEvents_LogDataSliceReceived(BinaryLogRecordKind recordKind, Stream stream) + { + eventArgsWriter.WriteBlob(recordKind, stream); + } + private void EventSource_AnyEventRaised(object sender, BuildEventArgs e) { Write(e); @@ -304,7 +356,7 @@ private void CollectImports(BuildEventArgs e) { projectImportsCollector.AddFile(projectArgs.ProjectFile); } - else if (e is MetaprojectGeneratedEventArgs metaprojectArgs) + else if (e is MetaprojectGeneratedEventArgs { metaprojectXml: { } } metaprojectArgs) { projectImportsCollector.AddFileFromMemory(metaprojectArgs.ProjectFile, metaprojectArgs.metaprojectXml); } @@ -319,13 +371,14 @@ private void CollectImports(BuildEventArgs e) /// /// /// - private void ProcessParameters() + private void ProcessParameters(out bool omitInitialInfo) { if (Parameters == null) { throw new LoggerException(ResourceUtilities.FormatResourceStringStripCodeAndKeyword("InvalidBinaryLoggerParameters", "")); } + omitInitialInfo = false; var parameters = Parameters.Split(MSBuildConstants.SemicolonChar, StringSplitOptions.RemoveEmptyEntries); foreach (var parameter in parameters) { @@ -341,6 +394,10 @@ private void ProcessParameters() { CollectProjectImports = ProjectImportsCollectionMode.ZipFile; } + else if (string.Equals(parameter, "OmitInitialInfo", StringComparison.OrdinalIgnoreCase)) + { + omitInitialInfo = true; + } else if (parameter.EndsWith(".binlog", StringComparison.OrdinalIgnoreCase)) { FilePath = parameter; diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsDispatcher.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsDispatcher.cs index 4a50a3d8e8b..db24d791ed2 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsDispatcher.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsDispatcher.cs @@ -85,6 +85,22 @@ public class EventArgsDispatcher : IEventSource /// public event BuildMessageEventHandler MessageRaised; + internal bool HasStructuredEventsSubscribers => + AnyEventRaised != null || + StatusEventRaised != null || + CustomEventRaised != null || + BuildStarted != null || + BuildFinished != null || + ProjectStarted != null || + ProjectFinished != null || + TargetStarted != null || + TargetFinished != null || + TaskStarted != null || + TaskFinished != null || + ErrorRaised != null || + WarningRaised != null || + MessageRaised != null; + /// /// Raise one of the events that is appropriate for the type of the BuildEventArgs /// diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs index 38e391565de..2c49c17c8a7 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs @@ -2,10 +2,14 @@ // The .NET Foundation licenses this file to you under the MIT license. using System; +using System.Buffers; using System.Collections; using System.Collections.Generic; using System.IO; +using System.IO.Compression; +using System.Linq; using System.Reflection; +using System.Runtime.CompilerServices; using System.Text; using Microsoft.Build.BackEnd; using Microsoft.Build.Collections; @@ -20,9 +24,13 @@ namespace Microsoft.Build.Logging /// public class BuildEventArgsReader : IBuildEventArgsReaderNotifications, IDisposable { - private readonly BinaryReader binaryReader; - private readonly int fileFormatVersion; - private long recordNumber = 0; + private readonly BinaryReader _binaryReader; + // This is used to verify that events deserialization is not overreading expected size. + private readonly TransparentReadStream _readStream; + private readonly int _fileFormatVersion; + private long _recordNumber = 0; + private bool _skipUnknownEvents; + private bool _skipUnknownEventParts; /// /// A list of string records we've encountered so far. If it's a small string, it will be the string directly. @@ -59,33 +67,140 @@ public class BuildEventArgsReader : IBuildEventArgsReaderNotifications, IDisposa /// The file format version of the log file being read. public BuildEventArgsReader(BinaryReader binaryReader, int fileFormatVersion) { - this.binaryReader = binaryReader; - this.fileFormatVersion = fileFormatVersion; + this._readStream = TransparentReadStream.EnsureTransparentReadStream(binaryReader.BaseStream); + // make sure the reader we're going to use wraps the transparent stream wrapper + this._binaryReader = binaryReader.BaseStream == _readStream + ? binaryReader + : new BinaryReader(_readStream); + this._fileFormatVersion = fileFormatVersion; } - public void Dispose() + /// + /// Directs whether the passed should be closed when this instance is disposed. + /// Defaults to "false". + /// + public bool CloseInput { private get; set; } = false; + + /// + /// Indicates whether unknown BuildEvents should be silently skipped. Read returns null otherwise. + /// Parameter is supported only if the file format supports forward compatible reading (version is 18 or higher). + /// + public bool SkipUnknownEvents { - stringStorage.Dispose(); + set + { + if (value) + { + EnsureForwardCompatibleReadingSupported(); + } + + _skipUnknownEvents = value; + } } /// - /// An event that allows the subscriber to be notified when a string is read from the binary log. - /// Subscriber may adjust the string by setting property. - /// The passed event arg can be reused and should not be stored. + /// Indicates whether unread parts of BuildEvents (probably added in newer format of particular BuildEvent)should be silently skipped. Exception thrown otherwise. + /// Parameter is supported only if the file format supports forward compatible reading (version is 18 or higher). /// - public event Action? StringReadDone; + public bool SkipUnknownEventParts + { + set + { + if (value) + { + EnsureForwardCompatibleReadingSupported(); + } + _skipUnknownEventParts = value; + } + } + + private void EnsureForwardCompatibleReadingSupported() + { + if (_fileFormatVersion < BinaryLogger.ForwardCompatibilityMinimalVersion) + { + throw new InvalidOperationException( + ResourceUtilities.FormatResourceStringStripCodeAndKeyword("Binlog_FwdCompatUnsupported", + _fileFormatVersion)); + } + } /// - /// An event that allows the caller to be notified when a string is encountered in the binary log. - /// BinaryReader passed in ctor is at the beginning of the string at this point. + /// Receives recoverable errors during reading. See for documentation on arguments. + /// Applicable mainly when or is set to true."/> /// - public event Action? StringEncountered; + public event Action? RecoverableReadError; + + public void Dispose() + { + stringStorage.Dispose(); + if (CloseInput) + { + _binaryReader.Dispose(); + } + } + + /// + public event Action? StringReadDone; + + internal int FileFormatVersion => _fileFormatVersion; + internal int MinimumReaderVersion { get; set; } = BinaryLogger.ForwardCompatibilityMinimalVersion; + + /// + internal event Action? EmbeddedContentRead; + + /// + public event Action? ArchiveFileEncountered; + + private SubStream? _lastSubStream; + + internal readonly record struct RawRecord(BinaryLogRecordKind RecordKind, Stream Stream); /// - /// Raised when the log reader encounters a binary blob embedded in the stream. - /// The arguments include the blob kind and the byte buffer with the contents. + /// Reads the next serialized log record from the . /// - internal event Action? OnBlobRead; + /// ArraySegment containing serialized BuildEventArgs record + internal RawRecord ReadRaw() + { + // This method is internal and condition is checked once before calling in loop, + // so avoiding it here on each call. + // But keeping it for documentation purposes - in case someone will try to call it and debug issues. + ////if (fileFormatVersion < 18) + ////{ + //// throw new InvalidOperationException( + //// $"Raw data reading is not supported for file format version {fileFormatVersion} (needs >=18)."); + ////} + + if (_lastSubStream?.IsAtEnd == false) + { + _lastSubStream.ReadToEnd(); + } + + BinaryLogRecordKind recordKind = PreprocessRecordsTillNextEvent(IsTextualDataRecord); + + if (recordKind == BinaryLogRecordKind.EndOfFile) + { + return new(recordKind, Stream.Null); + } + + int serializedEventLength = ReadInt32(); + Stream stream = _binaryReader.BaseStream.Slice(serializedEventLength); + + _lastSubStream = stream as SubStream; + + _recordNumber += 1; + + return new(recordKind, stream); + } + + [MethodImpl(MethodImplOptions.AggressiveInlining)] + private void CheckErrorsSubscribed() + { + if ((_skipUnknownEvents || _skipUnknownEventParts) && RecoverableReadError == null) + { + throw new InvalidOperationException( + ResourceUtilities.GetResourceString("Binlog_MissingRecoverableErrorSubscribeError")); + } + } /// /// Reads the next log record from the . @@ -96,11 +211,131 @@ public void Dispose() /// public BuildEventArgs? Read() { + CheckErrorsSubscribed(); + BuildEventArgs? result = null; + while (result == null) + { + BinaryLogRecordKind recordKind = PreprocessRecordsTillNextEvent(IsAuxiliaryRecord); + + if (recordKind == BinaryLogRecordKind.EndOfFile) + { + return null; + } + + int serializedEventLength = 0; + if (_fileFormatVersion >= BinaryLogger.ForwardCompatibilityMinimalVersion) + { + serializedEventLength = ReadInt32(); // record length + _readStream.BytesCountAllowedToRead = serializedEventLength; + } + + bool hasError = false; + try + { + result = ReadBuildEventArgs(recordKind); + } + catch (Exception e) when ( + // We throw this on mismatches in metadata (name-value list, strings index). + e is InvalidDataException || + // Thrown when BinaryReader is unable to deserialize binary data into expected type. + e is FormatException || + // Thrown when we attempt to read more bytes than what is in the next event chunk. + (e is EndOfStreamException && _readStream.BytesCountAllowedToReadRemaining <= 0)) + { + hasError = true; + + string ErrorFactory() => + ResourceUtilities.FormatResourceStringStripCodeAndKeyword("Binlog_ReaderMismatchedRead", + _recordNumber, serializedEventLength, e.GetType(), e.Message) + (_skipUnknownEvents + ? " " + ResourceUtilities.GetResourceString("Binlog_ReaderSkippingRecord") + : string.Empty); + + HandleError(ErrorFactory, _skipUnknownEvents, ReaderErrorType.UnknownFormatOfEventData, recordKind, e); + } + + if (result == null && !hasError) + { + string ErrorFactory() => + ResourceUtilities.FormatResourceStringStripCodeAndKeyword("Binlog_ReaderUnknownType", + _recordNumber, serializedEventLength, recordKind) + (_skipUnknownEvents + ? " " + ResourceUtilities.GetResourceString("Binlog_ReaderSkippingRecord") + : string.Empty); + + HandleError(ErrorFactory, _skipUnknownEvents, ReaderErrorType.UnknownEventType, recordKind); + } + + if (_readStream.BytesCountAllowedToReadRemaining > 0) + { + string ErrorFactory() => ResourceUtilities.FormatResourceStringStripCodeAndKeyword( + "Binlog_ReaderUnderRead", _recordNumber, serializedEventLength, + serializedEventLength - _readStream.BytesCountAllowedToReadRemaining); + + HandleError(ErrorFactory, _skipUnknownEventParts, ReaderErrorType.UnknownEventData, recordKind); + } + + _recordNumber += 1; + } + + return result; + + void HandleError(FormatErrorMessage msgFactory, bool noThrow, ReaderErrorType readerErrorType, BinaryLogRecordKind recordKind, Exception? innerException = null) + { + if (noThrow) + { + RecoverableReadError?.Invoke(new BinaryLogReaderErrorEventArgs(readerErrorType, recordKind, msgFactory)); + SkipBytes(_readStream.BytesCountAllowedToReadRemaining); + } + else + { + throw new InvalidDataException(msgFactory(), innerException); + } + } + } + + private BuildEventArgs? ReadBuildEventArgs(BinaryLogRecordKind recordKind) + => recordKind switch + { + BinaryLogRecordKind.BuildStarted => ReadBuildStartedEventArgs(), + BinaryLogRecordKind.BuildFinished => ReadBuildFinishedEventArgs(), + BinaryLogRecordKind.ProjectStarted => ReadProjectStartedEventArgs(), + BinaryLogRecordKind.ProjectFinished => ReadProjectFinishedEventArgs(), + BinaryLogRecordKind.TargetStarted => ReadTargetStartedEventArgs(), + BinaryLogRecordKind.TargetFinished => ReadTargetFinishedEventArgs(), + BinaryLogRecordKind.TaskStarted => ReadTaskStartedEventArgs(), + BinaryLogRecordKind.TaskFinished => ReadTaskFinishedEventArgs(), + BinaryLogRecordKind.Error => ReadBuildErrorEventArgs(), + BinaryLogRecordKind.Warning => ReadBuildWarningEventArgs(), + BinaryLogRecordKind.Message => ReadBuildMessageEventArgs(), + BinaryLogRecordKind.CriticalBuildMessage => ReadCriticalBuildMessageEventArgs(), + BinaryLogRecordKind.TaskCommandLine => ReadTaskCommandLineEventArgs(), + BinaryLogRecordKind.TaskParameter => ReadTaskParameterEventArgs(), + BinaryLogRecordKind.ProjectEvaluationStarted => ReadProjectEvaluationStartedEventArgs(), + BinaryLogRecordKind.ProjectEvaluationFinished => ReadProjectEvaluationFinishedEventArgs(), + BinaryLogRecordKind.ProjectImported => ReadProjectImportedEventArgs(), + BinaryLogRecordKind.TargetSkipped => ReadTargetSkippedEventArgs(), + BinaryLogRecordKind.EnvironmentVariableRead => ReadEnvironmentVariableReadEventArgs(), + BinaryLogRecordKind.ResponseFileUsed => ReadResponseFileUsedEventArgs(), + BinaryLogRecordKind.PropertyReassignment => ReadPropertyReassignmentEventArgs(), + BinaryLogRecordKind.UninitializedPropertyRead => ReadUninitializedPropertyReadEventArgs(), + BinaryLogRecordKind.PropertyInitialValueSet => ReadPropertyInitialValueSetEventArgs(), + BinaryLogRecordKind.AssemblyLoad => ReadAssemblyLoadEventArgs(), + _ => null + }; + + private void SkipBytes(int count) + { + _binaryReader.BaseStream.Seek(count, SeekOrigin.Current); + } + + private BinaryLogRecordKind PreprocessRecordsTillNextEvent(Func isPreprocessRecord) + { + _readStream.BytesCountAllowedToRead = null; + BinaryLogRecordKind recordKind = (BinaryLogRecordKind)ReadInt32(); // Skip over data storage records since they don't result in a BuildEventArgs. // just ingest their data and continue. - while (IsAuxiliaryRecord(recordKind)) + while (isPreprocessRecord(recordKind)) { // these are ordered by commonality if (recordKind == BinaryLogRecordKind.String) @@ -110,99 +345,19 @@ public void Dispose() else if (recordKind == BinaryLogRecordKind.NameValueList) { ReadNameValueList(); + _readStream.BytesCountAllowedToRead = null; } else if (recordKind == BinaryLogRecordKind.ProjectImportArchive) { - ReadBlob(recordKind); + ReadEmbeddedContent(recordKind); } - recordNumber += 1; + _recordNumber += 1; recordKind = (BinaryLogRecordKind)ReadInt32(); } - BuildEventArgs? result = null; - switch (recordKind) - { - case BinaryLogRecordKind.EndOfFile: - break; - case BinaryLogRecordKind.BuildStarted: - result = ReadBuildStartedEventArgs(); - break; - case BinaryLogRecordKind.BuildFinished: - result = ReadBuildFinishedEventArgs(); - break; - case BinaryLogRecordKind.ProjectStarted: - result = ReadProjectStartedEventArgs(); - break; - case BinaryLogRecordKind.ProjectFinished: - result = ReadProjectFinishedEventArgs(); - break; - case BinaryLogRecordKind.TargetStarted: - result = ReadTargetStartedEventArgs(); - break; - case BinaryLogRecordKind.TargetFinished: - result = ReadTargetFinishedEventArgs(); - break; - case BinaryLogRecordKind.TaskStarted: - result = ReadTaskStartedEventArgs(); - break; - case BinaryLogRecordKind.TaskFinished: - result = ReadTaskFinishedEventArgs(); - break; - case BinaryLogRecordKind.Error: - result = ReadBuildErrorEventArgs(); - break; - case BinaryLogRecordKind.Warning: - result = ReadBuildWarningEventArgs(); - break; - case BinaryLogRecordKind.Message: - result = ReadBuildMessageEventArgs(); - break; - case BinaryLogRecordKind.CriticalBuildMessage: - result = ReadCriticalBuildMessageEventArgs(); - break; - case BinaryLogRecordKind.TaskCommandLine: - result = ReadTaskCommandLineEventArgs(); - break; - case BinaryLogRecordKind.TaskParameter: - result = ReadTaskParameterEventArgs(); - break; - case BinaryLogRecordKind.ProjectEvaluationStarted: - result = ReadProjectEvaluationStartedEventArgs(); - break; - case BinaryLogRecordKind.ProjectEvaluationFinished: - result = ReadProjectEvaluationFinishedEventArgs(); - break; - case BinaryLogRecordKind.ProjectImported: - result = ReadProjectImportedEventArgs(); - break; - case BinaryLogRecordKind.TargetSkipped: - result = ReadTargetSkippedEventArgs(); - break; - case BinaryLogRecordKind.EnvironmentVariableRead: - result = ReadEnvironmentVariableReadEventArgs(); - break; - case BinaryLogRecordKind.ResponseFileUsed: - result = ReadResponseFileUsedEventArgs(); - break; - case BinaryLogRecordKind.PropertyReassignment: - result = ReadPropertyReassignmentEventArgs(); - break; - case BinaryLogRecordKind.UninitializedPropertyRead: - result = ReadUninitializedPropertyReadEventArgs(); - break; - case BinaryLogRecordKind.PropertyInitialValueSet: - result = ReadPropertyInitialValueSetEventArgs(); - break; - case BinaryLogRecordKind.AssemblyLoad: - result = ReadAssemblyLoadEventArgs(); - break; - } - - recordNumber += 1; - - return result; + return recordKind; } private static bool IsAuxiliaryRecord(BinaryLogRecordKind recordKind) @@ -212,15 +367,94 @@ private static bool IsAuxiliaryRecord(BinaryLogRecordKind recordKind) || recordKind == BinaryLogRecordKind.ProjectImportArchive; } - private void ReadBlob(BinaryLogRecordKind kind) + private static bool IsTextualDataRecord(BinaryLogRecordKind recordKind) + { + return recordKind == BinaryLogRecordKind.String + || recordKind == BinaryLogRecordKind.ProjectImportArchive; + } + + private void ReadEmbeddedContent(BinaryLogRecordKind recordKind) { int length = ReadInt32(); - byte[] bytes = binaryReader.ReadBytes(length); - OnBlobRead?.Invoke(kind, bytes); + + if (ArchiveFileEncountered != null) + { + // We could create ZipArchive over the target stream, and write to that directly, + // however, binlog format needs to know stream size upfront - which is unknown, + // so we would need to write the size after - and that would require the target stream to be seekable (which it's not) + ProjectImportsCollector? projectImportsCollector = null; + + if (EmbeddedContentRead != null) + { + projectImportsCollector = + new ProjectImportsCollector(Path.GetRandomFileName(), false, runOnBackground: false); + } + + Stream embeddedStream = _binaryReader.BaseStream.Slice(length); + + // We are intentionally not grace handling corrupt embedded stream + + using var zipArchive = new ZipArchive(embeddedStream, ZipArchiveMode.Read); + + foreach (var entry in zipArchive.Entries/*.OrderBy(e => e.LastWriteTime)*/) + { + var file = ArchiveStream.From(entry); + ArchiveFileEventArgs archiveFileEventArgs = new(file); + // ArchiveFileEventArgs is not IDisposable as we do not want to clutter exposed API + using var cleanupScope = new CleanupScope(archiveFileEventArgs.Dispose); + ArchiveFileEncountered(archiveFileEventArgs); + + if (projectImportsCollector != null) + { + var resultFile = archiveFileEventArgs.ArchiveData; + + if (resultFile is ArchiveStream archiveStream) + { + projectImportsCollector.AddFileFromMemory( + archiveStream.FullPath, + archiveStream.ContentReader.BaseStream, + makePathAbsolute: false, + entryCreationStamp: entry.LastWriteTime); + } + else + { + projectImportsCollector.AddFileFromMemory( + resultFile.FullPath, + resultFile.ToArchiveFile().Content, + makePathAbsolute: false, + entryCreationStamp: entry.LastWriteTime); + } + } + } + + // Once embedded files are replayed one by one - we can send the resulting stream to subscriber + if (EmbeddedContentRead != null) + { + projectImportsCollector!.ProcessResult( + streamToEmbed => EmbeddedContentRead(new EmbeddedContentEventArgs(recordKind, streamToEmbed)), + error => throw new InvalidDataException(error)); + projectImportsCollector.DeleteArchive(); + } + } + else if (EmbeddedContentRead != null) + { + EmbeddedContentRead(new EmbeddedContentEventArgs( + recordKind, + _binaryReader.BaseStream.Slice(length))); + } + else + { + SkipBytes(length); + } } private void ReadNameValueList() { + if (_fileFormatVersion >= BinaryLogger.ForwardCompatibilityMinimalVersion) + { + _readStream.BytesCountAllowedToRead = ReadInt32(); + } + int count = ReadInt32(); var list = new (int, int)[count]; @@ -262,7 +496,7 @@ private IDictionary GetNameValueList(int id) // this should never happen for valid binlogs throw new InvalidDataException( - $"NameValueList record number {recordNumber} is invalid: index {id} is not within {stringRecords.Count}."); + $"NameValueList record number {_recordNumber} is invalid: index {id} is not within {nameValueListRecords.Count}."); } private readonly StringReadEventArgs stringReadEventArgs = new StringReadEventArgs(string.Empty); @@ -280,7 +514,7 @@ private BuildEventArgs ReadProjectImportedEventArgs() bool importIgnored = false; // the ImportIgnored field was introduced in file format version 3 - if (fileFormatVersion > 2) + if (_fileFormatVersion > 2) { importIgnored = ReadBoolean(); } @@ -317,7 +551,7 @@ private BuildEventArgs ReadTargetSkippedEventArgs() bool originallySucceeded = false; TargetSkipReason skipReason = TargetSkipReason.None; BuildEventContext? originalBuildEventContext = null; - if (fileFormatVersion >= 13) + if (_fileFormatVersion >= 13) { condition = ReadOptionalString(); evaluatedCondition = ReadOptionalString(); @@ -333,10 +567,10 @@ private BuildEventArgs ReadTargetSkippedEventArgs() var buildReason = (TargetBuiltReason)ReadInt32(); - if (fileFormatVersion >= 14) + if (_fileFormatVersion >= 14) { skipReason = (TargetSkipReason)ReadInt32(); - originalBuildEventContext = binaryReader.ReadOptionalBuildEventContext(); + originalBuildEventContext = _binaryReader.ReadOptionalBuildEventContext(); } var e = new TargetSkippedEventArgs( @@ -417,10 +651,15 @@ private BuildEventArgs ReadProjectEvaluationFinishedEventArgs() }; SetCommonFields(e, fields); - if (fileFormatVersion >= 12) + if (_fileFormatVersion >= 12) { IEnumerable? globalProperties = null; - if (ReadBoolean()) + // In newer versions, we store the global properties always, as it handles + // null and empty within WriteProperties already. + // This saves a single boolean, but mainly doesn't hide the difference between null and empty + // during write->read roundtrip. + if (_fileFormatVersion >= BinaryLogger.ForwardCompatibilityMinimalVersion || + ReadBoolean()) { globalProperties = ReadStringDictionary(); } @@ -434,7 +673,7 @@ private BuildEventArgs ReadProjectEvaluationFinishedEventArgs() } // ProfilerResult was introduced in version 5 - if (fileFormatVersion > 4) + if (_fileFormatVersion > 4) { var hasProfileData = ReadBoolean(); if (hasProfileData) @@ -472,9 +711,11 @@ private BuildEventArgs ReadProjectStartedEventArgs() IDictionary? globalProperties = null; - if (fileFormatVersion > 6) + if (_fileFormatVersion > 6) { - if (ReadBoolean()) + // See ReadProjectEvaluationFinishedEventArgs for details on why we always store global properties in newer version. + if (_fileFormatVersion >= BinaryLogger.ForwardCompatibilityMinimalVersion || + ReadBoolean()) { globalProperties = ReadStringDictionary(); } @@ -522,7 +763,7 @@ private BuildEventArgs ReadTargetStartedEventArgs() var targetFile = ReadOptionalString(); var parentTarget = ReadOptionalString(); // BuildReason was introduced in version 4 - var buildReason = fileFormatVersion > 3 ? (TargetBuiltReason)ReadInt32() : TargetBuiltReason.None; + var buildReason = _fileFormatVersion > 3 ? (TargetBuiltReason)ReadInt32() : TargetBuiltReason.None; var e = new TargetStartedEventArgs( fields.Message, @@ -950,6 +1191,7 @@ private AssemblyLoadBuildEventArgs ReadAssemblyLoadEventArgs() mvid, appDomainName); SetCommonFields(e, fields); + e.ProjectFile = fields.ProjectFile; return e; } @@ -1078,7 +1320,7 @@ private BuildEventArgsFields ReadBuildEventArgsFields(bool readImportance = fals result.Arguments = arguments; } - if ((fileFormatVersion < 13 && readImportance) || (fileFormatVersion >= 13 && (flags & BuildEventArgsFieldFlags.Importance) != 0)) + if ((_fileFormatVersion < 13 && readImportance) || (_fileFormatVersion >= 13 && (flags & BuildEventArgsFieldFlags.Importance) != 0)) { result.Importance = (MessageImportance)ReadInt32(); } @@ -1137,7 +1379,7 @@ private BuildEventContext ReadBuildEventContext() // evaluationId was introduced in format version 2 int evaluationId = BuildEventContext.InvalidEvaluationId; - if (fileFormatVersion > 1) + if (_fileFormatVersion > 1) { evaluationId = ReadInt32(); } @@ -1155,7 +1397,7 @@ private BuildEventContext ReadBuildEventContext() private IDictionary? ReadStringDictionary() { - if (fileFormatVersion < 10) + if (_fileFormatVersion < 10) { return ReadLegacyStringDictionary(); } @@ -1207,7 +1449,7 @@ private ITaskItem ReadTaskItem() // so we only have to write the name once, and then the count of items // with that name. When reading a legacy binlog we need to read the // old style flat list where the name is duplicated for each item. - if (fileFormatVersion < 10) + if (_fileFormatVersion < 10) { int count = ReadInt32(); if (count == 0) @@ -1223,7 +1465,7 @@ private ITaskItem ReadTaskItem() list[i] = new DictionaryEntry(itemName, item); } } - else if (fileFormatVersion < 12) + else if (_fileFormatVersion < 12) { int count = ReadInt32(); if (count == 0) @@ -1302,8 +1544,7 @@ private ITaskItem ReadTaskItem() private string ReadString() { - this.StringEncountered?.Invoke(); - string text = binaryReader.ReadString(); + string text = _binaryReader.ReadString(); if (this.StringReadDone != null) { stringReadEventArgs.Reuse(text); @@ -1315,7 +1556,7 @@ private string ReadString() private string? ReadOptionalString() { - if (fileFormatVersion < 10) + if (_fileFormatVersion < 10) { if (ReadBoolean()) { @@ -1332,7 +1573,7 @@ private string ReadString() private string? ReadDeduplicatedString() { - if (fileFormatVersion < 10) + if (_fileFormatVersion < 10) { return ReadString(); } @@ -1364,7 +1605,7 @@ private string ReadString() // this should never happen for valid binlogs throw new InvalidDataException( - $"String record number {recordNumber} is invalid: string index {index} is not within {stringRecords.Count}."); + $"String record number {_recordNumber} is invalid: string index {index} is not within {stringRecords.Count}."); } private int ReadInt32() @@ -1372,32 +1613,32 @@ private int ReadInt32() // on some platforms (net5) this method was added to BinaryReader // but it's not available on others. Call our own extension method // explicitly to avoid ambiguity. - return BinaryReaderExtensions.Read7BitEncodedInt(binaryReader); + return BinaryReaderExtensions.Read7BitEncodedInt(_binaryReader); } private long ReadInt64() { - return binaryReader.ReadInt64(); + return _binaryReader.ReadInt64(); } private bool ReadBoolean() { - return binaryReader.ReadBoolean(); + return _binaryReader.ReadBoolean(); } private Guid ReadGuid() { - return new Guid(binaryReader.ReadBytes(16 /*sizeof(Guid) - to avoid unsafe context, Guid will never change in size */)); + return new Guid(_binaryReader.ReadBytes(16 /*sizeof(Guid) - to avoid unsafe context, Guid will never change in size */)); } private DateTime ReadDateTime() { - return new DateTime(binaryReader.ReadInt64(), (DateTimeKind)ReadInt32()); + return new DateTime(_binaryReader.ReadInt64(), (DateTimeKind)ReadInt32()); } private TimeSpan ReadTimeSpan() { - return new TimeSpan(binaryReader.ReadInt64()); + return new TimeSpan(_binaryReader.ReadInt64()); } private ProfiledLocation ReadProfiledLocation() @@ -1426,7 +1667,7 @@ private EvaluationLocation ReadEvaluationLocation() } // Id and parent Id were introduced in version 6 - if (fileFormatVersion > 5) + if (_fileFormatVersion > 5) { var id = ReadInt64(); long? parentId = null; diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs index 0a21182e83c..8a8311e1fd6 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs @@ -2,6 +2,7 @@ // The .NET Foundation licenses this file to you under the MIT license. using System; +using System.Buffers; using System.Collections; using System.Collections.Generic; using System.Globalization; @@ -35,6 +36,13 @@ internal class BuildEventArgsWriter /// private readonly MemoryStream currentRecordStream; + /// + /// For NameValueList we need to prefix the storage size + /// (distinct from values count due to variable int encoding) + /// So using same technique as with 'currentRecordStream'. + /// + private readonly MemoryStream nameValueListStream; + /// /// The binary writer around the originalStream. /// @@ -121,6 +129,8 @@ public BuildEventArgsWriter(BinaryWriter binaryWriter) // starting point to avoid reallocations in the common case this.currentRecordStream = new MemoryStream(65536); + this.nameValueListStream = new MemoryStream(256); + this.originalBinaryWriter = binaryWriter; this.currentRecordWriter = new BinaryWriter(currentRecordStream); @@ -132,11 +142,20 @@ public BuildEventArgsWriter(BinaryWriter binaryWriter) /// public void Write(BuildEventArgs e) { - WriteCore(e); + // reset the temp stream (in case last usage forgot to do so). + this.currentRecordStream.SetLength(0); + BinaryLogRecordKind eventKind = WriteCore(e); - // flush the current record and clear the MemoryStream to prepare for next use - currentRecordStream.WriteTo(originalStream); - currentRecordStream.SetLength(0); + FlushRecordToFinalStream(eventKind, currentRecordStream); + } + + private void FlushRecordToFinalStream(BinaryLogRecordKind recordKind, MemoryStream recordStream) + { + using var redirectionScope = RedirectWritesToOriginalWriter(); + Write(recordKind); + Write((int)recordStream.Length); + recordStream.WriteTo(originalStream); + recordStream.SetLength(0); } /* @@ -178,23 +197,23 @@ Base types and inheritance ("EventArgs" suffix omitted): ExtendedCustomBuild */ - private void WriteCore(BuildEventArgs e) + private BinaryLogRecordKind WriteCore(BuildEventArgs e) { switch (e) { - case BuildMessageEventArgs buildMessage: Write(buildMessage); break; - case TaskStartedEventArgs taskStarted: Write(taskStarted); break; - case TaskFinishedEventArgs taskFinished: Write(taskFinished); break; - case TargetStartedEventArgs targetStarted: Write(targetStarted); break; - case TargetFinishedEventArgs targetFinished: Write(targetFinished); break; - case BuildErrorEventArgs buildError: Write(buildError); break; - case BuildWarningEventArgs buildWarning: Write(buildWarning); break; - case ProjectStartedEventArgs projectStarted: Write(projectStarted); break; - case ProjectFinishedEventArgs projectFinished: Write(projectFinished); break; - case BuildStartedEventArgs buildStarted: Write(buildStarted); break; - case BuildFinishedEventArgs buildFinished: Write(buildFinished); break; - case ProjectEvaluationStartedEventArgs projectEvaluationStarted: Write(projectEvaluationStarted); break; - case ProjectEvaluationFinishedEventArgs projectEvaluationFinished: Write(projectEvaluationFinished); break; + case BuildMessageEventArgs buildMessage: return Write(buildMessage); + case TaskStartedEventArgs taskStarted: return Write(taskStarted); + case TaskFinishedEventArgs taskFinished: return Write(taskFinished); + case TargetStartedEventArgs targetStarted: return Write(targetStarted); + case TargetFinishedEventArgs targetFinished: return Write(targetFinished); + case BuildErrorEventArgs buildError: return Write(buildError); + case BuildWarningEventArgs buildWarning: return Write(buildWarning); + case ProjectStartedEventArgs projectStarted: return Write(projectStarted); + case ProjectFinishedEventArgs projectFinished: return Write(projectFinished); + case BuildStartedEventArgs buildStarted: return Write(buildStarted); + case BuildFinishedEventArgs buildFinished: return Write(buildFinished); + case ProjectEvaluationStartedEventArgs projectEvaluationStarted: return Write(projectEvaluationStarted); + case ProjectEvaluationFinishedEventArgs projectEvaluationFinished: return Write(projectEvaluationFinished); default: // convert all unrecognized objects to message // and just preserve the message @@ -224,25 +243,13 @@ private void WriteCore(BuildEventArgs e) e.Timestamp); } buildMessageEventArgs.BuildEventContext = e.BuildEventContext ?? BuildEventContext.Invalid; - Write(buildMessageEventArgs); - break; + return Write(buildMessageEventArgs); } } - public void WriteBlob(BinaryLogRecordKind kind, byte[] bytes) - { - // write the blob directly to the underlying writer, - // bypassing the memory stream - using var redirection = RedirectWritesToOriginalWriter(); - - Write(kind); - Write(bytes.Length); - Write(bytes); - } - public void WriteBlob(BinaryLogRecordKind kind, Stream stream) { - if (stream.Length > int.MaxValue) + if (stream.CanSeek && stream.Length > int.MaxValue) { throw new ArgumentOutOfRangeException(nameof(stream)); } @@ -253,7 +260,7 @@ public void WriteBlob(BinaryLogRecordKind kind, Stream stream) Write(kind); Write((int)stream.Length); - Write(stream); + WriteToOriginalStream(stream); } /// @@ -263,28 +270,17 @@ public void WriteBlob(BinaryLogRecordKind kind, Stream stream) /// private IDisposable RedirectWritesToOriginalWriter() { - binaryWriter = originalBinaryWriter; - return new RedirectionScope(this); + return RedirectWritesToDifferentWriter(originalBinaryWriter, currentRecordWriter); } - private struct RedirectionScope : IDisposable + private IDisposable RedirectWritesToDifferentWriter(BinaryWriter inScopeWriter, BinaryWriter afterScopeWriter) { - private readonly BuildEventArgsWriter _writer; - - public RedirectionScope(BuildEventArgsWriter buildEventArgsWriter) - { - _writer = buildEventArgsWriter; - } - - public void Dispose() - { - _writer.binaryWriter = _writer.currentRecordWriter; - } + binaryWriter = inScopeWriter; + return new CleanupScope(() => binaryWriter = afterScopeWriter); } - private void Write(BuildStartedEventArgs e) + private BinaryLogRecordKind Write(BuildStartedEventArgs e) { - Write(BinaryLogRecordKind.BuildStarted); WriteBuildEventArgsFields(e); if (Traits.LogAllEnvironmentVariables) { @@ -294,38 +290,31 @@ private void Write(BuildStartedEventArgs e) { Write(e.BuildEnvironment?.Where(kvp => EnvironmentUtilities.IsWellKnownEnvironmentDerivedProperty(kvp.Key))); } + + return BinaryLogRecordKind.BuildStarted; } - private void Write(BuildFinishedEventArgs e) + private BinaryLogRecordKind Write(BuildFinishedEventArgs e) { - Write(BinaryLogRecordKind.BuildFinished); WriteBuildEventArgsFields(e); Write(e.Succeeded); + + return BinaryLogRecordKind.BuildFinished; } - private void Write(ProjectEvaluationStartedEventArgs e) + private BinaryLogRecordKind Write(ProjectEvaluationStartedEventArgs e) { - Write(BinaryLogRecordKind.ProjectEvaluationStarted); WriteBuildEventArgsFields(e, writeMessage: false); WriteDeduplicatedString(e.ProjectFile); + return BinaryLogRecordKind.ProjectEvaluationStarted; } - private void Write(ProjectEvaluationFinishedEventArgs e) + private BinaryLogRecordKind Write(ProjectEvaluationFinishedEventArgs e) { - Write(BinaryLogRecordKind.ProjectEvaluationFinished); - WriteBuildEventArgsFields(e, writeMessage: false); WriteDeduplicatedString(e.ProjectFile); - if (e.GlobalProperties == null) - { - Write(false); - } - else - { - Write(true); - WriteProperties(e.GlobalProperties); - } + WriteProperties(e.GlobalProperties); WriteProperties(e.Properties); @@ -343,11 +332,12 @@ private void Write(ProjectEvaluationFinishedEventArgs e) Write(item.Value); } } + + return BinaryLogRecordKind.ProjectEvaluationFinished; } - private void Write(ProjectStartedEventArgs e) + private BinaryLogRecordKind Write(ProjectStartedEventArgs e) { - Write(BinaryLogRecordKind.ProjectStarted); WriteBuildEventArgsFields(e, writeMessage: false); if (e.ParentProjectBuildEventContext == null) @@ -366,75 +356,73 @@ private void Write(ProjectStartedEventArgs e) WriteDeduplicatedString(e.TargetNames); WriteDeduplicatedString(e.ToolsVersion); - if (e.GlobalProperties == null) - { - Write(false); - } - else - { - Write(true); - Write(e.GlobalProperties); - } + Write(e.GlobalProperties); WriteProperties(e.Properties); WriteProjectItems(e.Items); + + return BinaryLogRecordKind.ProjectStarted; } - private void Write(ProjectFinishedEventArgs e) + private BinaryLogRecordKind Write(ProjectFinishedEventArgs e) { - Write(BinaryLogRecordKind.ProjectFinished); WriteBuildEventArgsFields(e, writeMessage: false); WriteDeduplicatedString(e.ProjectFile); Write(e.Succeeded); + + return BinaryLogRecordKind.ProjectFinished; } - private void Write(TargetStartedEventArgs e) + private BinaryLogRecordKind Write(TargetStartedEventArgs e) { - Write(BinaryLogRecordKind.TargetStarted); WriteBuildEventArgsFields(e, writeMessage: false); WriteDeduplicatedString(e.TargetName); WriteDeduplicatedString(e.ProjectFile); WriteDeduplicatedString(e.TargetFile); WriteDeduplicatedString(e.ParentTarget); Write((int)e.BuildReason); + + return BinaryLogRecordKind.TargetStarted; } - private void Write(TargetFinishedEventArgs e) + private BinaryLogRecordKind Write(TargetFinishedEventArgs e) { - Write(BinaryLogRecordKind.TargetFinished); WriteBuildEventArgsFields(e, writeMessage: false); Write(e.Succeeded); WriteDeduplicatedString(e.ProjectFile); WriteDeduplicatedString(e.TargetFile); WriteDeduplicatedString(e.TargetName); WriteTaskItemList(e.TargetOutputs); + + return BinaryLogRecordKind.TargetFinished; } - private void Write(TaskStartedEventArgs e) + private BinaryLogRecordKind Write(TaskStartedEventArgs e) { - Write(BinaryLogRecordKind.TaskStarted); WriteBuildEventArgsFields(e, writeMessage: false, writeLineAndColumn: true); Write(e.LineNumber); Write(e.ColumnNumber); WriteDeduplicatedString(e.TaskName); WriteDeduplicatedString(e.ProjectFile); WriteDeduplicatedString(e.TaskFile); + + return BinaryLogRecordKind.TaskStarted; } - private void Write(TaskFinishedEventArgs e) + private BinaryLogRecordKind Write(TaskFinishedEventArgs e) { - Write(BinaryLogRecordKind.TaskFinished); WriteBuildEventArgsFields(e, writeMessage: false); Write(e.Succeeded); WriteDeduplicatedString(e.TaskName); WriteDeduplicatedString(e.ProjectFile); WriteDeduplicatedString(e.TaskFile); + + return BinaryLogRecordKind.TaskFinished; } - private void Write(BuildErrorEventArgs e) + private BinaryLogRecordKind Write(BuildErrorEventArgs e) { - Write(BinaryLogRecordKind.Error); WriteBuildEventArgsFields(e); WriteArguments(e.RawArguments); WriteDeduplicatedString(e.Subcategory); @@ -445,11 +433,12 @@ private void Write(BuildErrorEventArgs e) Write(e.ColumnNumber); Write(e.EndLineNumber); Write(e.EndColumnNumber); + + return BinaryLogRecordKind.Error; } - private void Write(BuildWarningEventArgs e) + private BinaryLogRecordKind Write(BuildWarningEventArgs e) { - Write(BinaryLogRecordKind.Warning); WriteBuildEventArgsFields(e); WriteArguments(e.RawArguments); WriteDeduplicatedString(e.Subcategory); @@ -460,42 +449,42 @@ private void Write(BuildWarningEventArgs e) Write(e.ColumnNumber); Write(e.EndLineNumber); Write(e.EndColumnNumber); + + return BinaryLogRecordKind.Warning; } - private void Write(BuildMessageEventArgs e) + private BinaryLogRecordKind Write(BuildMessageEventArgs e) { switch (e) { - case ResponseFileUsedEventArgs responseFileUsed: Write(responseFileUsed); break; - case TaskParameterEventArgs taskParameter: Write(taskParameter); break; - case ProjectImportedEventArgs projectImported: Write(projectImported); break; - case TargetSkippedEventArgs targetSkipped: Write(targetSkipped); break; - case PropertyReassignmentEventArgs propertyReassignment: Write(propertyReassignment); break; - case TaskCommandLineEventArgs taskCommandLine: Write(taskCommandLine); break; - case UninitializedPropertyReadEventArgs uninitializedPropertyRead: Write(uninitializedPropertyRead); break; - case EnvironmentVariableReadEventArgs environmentVariableRead: Write(environmentVariableRead); break; - case PropertyInitialValueSetEventArgs propertyInitialValueSet: Write(propertyInitialValueSet); break; - case CriticalBuildMessageEventArgs criticalBuildMessage: Write(criticalBuildMessage); break; - case AssemblyLoadBuildEventArgs assemblyLoad: Write(assemblyLoad); break; + case ResponseFileUsedEventArgs responseFileUsed: return Write(responseFileUsed); + case TaskParameterEventArgs taskParameter: return Write(taskParameter); + case ProjectImportedEventArgs projectImported: return Write(projectImported); + case TargetSkippedEventArgs targetSkipped: return Write(targetSkipped); + case PropertyReassignmentEventArgs propertyReassignment: return Write(propertyReassignment); + case TaskCommandLineEventArgs taskCommandLine: return Write(taskCommandLine); + case UninitializedPropertyReadEventArgs uninitializedPropertyRead: return Write(uninitializedPropertyRead); + case EnvironmentVariableReadEventArgs environmentVariableRead: return Write(environmentVariableRead); + case PropertyInitialValueSetEventArgs propertyInitialValueSet: return Write(propertyInitialValueSet); + case CriticalBuildMessageEventArgs criticalBuildMessage: return Write(criticalBuildMessage); + case AssemblyLoadBuildEventArgs assemblyLoad: return Write(assemblyLoad); default: // actual BuildMessageEventArgs - Write(BinaryLogRecordKind.Message); WriteMessageFields(e, writeImportance: true); - break; + return BinaryLogRecordKind.Message; } } - private void Write(ProjectImportedEventArgs e) + private BinaryLogRecordKind Write(ProjectImportedEventArgs e) { - Write(BinaryLogRecordKind.ProjectImported); WriteMessageFields(e); Write(e.ImportIgnored); WriteDeduplicatedString(e.ImportedProjectFile); WriteDeduplicatedString(e.UnexpandedProject); + return BinaryLogRecordKind.ProjectImported; } - private void Write(TargetSkippedEventArgs e) + private BinaryLogRecordKind Write(TargetSkippedEventArgs e) { - Write(BinaryLogRecordKind.TargetSkipped); WriteMessageFields(e, writeMessage: false); WriteDeduplicatedString(e.TargetFile); WriteDeduplicatedString(e.TargetName); @@ -506,11 +495,11 @@ private void Write(TargetSkippedEventArgs e) Write((int)e.BuildReason); Write((int)e.SkipReason); binaryWriter.WriteOptionalBuildEventContext(e.OriginalBuildEventContext); + return BinaryLogRecordKind.TargetSkipped; } - private void Write(AssemblyLoadBuildEventArgs e) + private BinaryLogRecordKind Write(AssemblyLoadBuildEventArgs e) { - Write(BinaryLogRecordKind.AssemblyLoad); WriteMessageFields(e, writeMessage: false, writeImportance: false); Write((int)e.LoadingContext); WriteDeduplicatedString(e.LoadingInitiator); @@ -518,63 +507,63 @@ private void Write(AssemblyLoadBuildEventArgs e) WriteDeduplicatedString(e.AssemblyPath); Write(e.MVID); WriteDeduplicatedString(e.AppDomainDescriptor); + return BinaryLogRecordKind.AssemblyLoad; } - private void Write(CriticalBuildMessageEventArgs e) + private BinaryLogRecordKind Write(CriticalBuildMessageEventArgs e) { - Write(BinaryLogRecordKind.CriticalBuildMessage); WriteMessageFields(e); + return BinaryLogRecordKind.CriticalBuildMessage; } - private void Write(PropertyReassignmentEventArgs e) + private BinaryLogRecordKind Write(PropertyReassignmentEventArgs e) { - Write(BinaryLogRecordKind.PropertyReassignment); WriteMessageFields(e, writeMessage: false, writeImportance: true); WriteDeduplicatedString(e.PropertyName); WriteDeduplicatedString(e.PreviousValue); WriteDeduplicatedString(e.NewValue); WriteDeduplicatedString(e.Location); + return BinaryLogRecordKind.PropertyReassignment; } - private void Write(UninitializedPropertyReadEventArgs e) + private BinaryLogRecordKind Write(UninitializedPropertyReadEventArgs e) { - Write(BinaryLogRecordKind.UninitializedPropertyRead); WriteMessageFields(e, writeImportance: true); WriteDeduplicatedString(e.PropertyName); + return BinaryLogRecordKind.UninitializedPropertyRead; } - private void Write(PropertyInitialValueSetEventArgs e) + private BinaryLogRecordKind Write(PropertyInitialValueSetEventArgs e) { - Write(BinaryLogRecordKind.PropertyInitialValueSet); WriteMessageFields(e, writeImportance: true); WriteDeduplicatedString(e.PropertyName); WriteDeduplicatedString(e.PropertyValue); WriteDeduplicatedString(e.PropertySource); + return BinaryLogRecordKind.PropertyInitialValueSet; } - private void Write(EnvironmentVariableReadEventArgs e) + private BinaryLogRecordKind Write(EnvironmentVariableReadEventArgs e) { - Write(BinaryLogRecordKind.EnvironmentVariableRead); WriteMessageFields(e, writeImportance: true); WriteDeduplicatedString(e.EnvironmentVariableName); + return BinaryLogRecordKind.EnvironmentVariableRead; } - private void Write(ResponseFileUsedEventArgs e) + private BinaryLogRecordKind Write(ResponseFileUsedEventArgs e) { - Write(BinaryLogRecordKind.ResponseFileUsed); WriteMessageFields(e); WriteDeduplicatedString(e.ResponseFilePath); + return BinaryLogRecordKind.ResponseFileUsed; } - private void Write(TaskCommandLineEventArgs e) + private BinaryLogRecordKind Write(TaskCommandLineEventArgs e) { - Write(BinaryLogRecordKind.TaskCommandLine); WriteMessageFields(e, writeMessage: false, writeImportance: true); WriteDeduplicatedString(e.CommandLine); WriteDeduplicatedString(e.TaskName); + return BinaryLogRecordKind.TaskCommandLine; } - private void Write(TaskParameterEventArgs e) + private BinaryLogRecordKind Write(TaskParameterEventArgs e) { - Write(BinaryLogRecordKind.TaskParameter); WriteMessageFields(e, writeMessage: false); Write((int)e.Kind); WriteDeduplicatedString(e.ItemType); @@ -584,6 +573,7 @@ private void Write(TaskParameterEventArgs e) { CheckForFilesToEmbed(e.ItemType, e.Items); } + return BinaryLogRecordKind.TaskParameter; } private void WriteBuildEventArgsFields(BuildEventArgs e, bool writeMessage = true, bool writeLineAndColumn = false) @@ -1078,19 +1068,27 @@ private void WriteNameValueList() /// private void WriteNameValueListRecord() { - // Switch the binaryWriter used by the Write* methods to the direct underlying stream writer. // We want this record to precede the record we're currently writing to currentRecordWriter - // which is backed by a MemoryStream buffer - using var redirectionScope = RedirectWritesToOriginalWriter(); + // We as well want to know the storage size (differs from nameValueIndexListBuffer.Count as + // we use variable integer encoding). + // So we redirect the writes to a MemoryStream and then flush the record to the final stream. + // All that is redirected away from the 'currentRecordStream' - that will be flushed last + + nameValueListStream.SetLength(0); + var nameValueListBw = new BinaryWriter(nameValueListStream); - Write(BinaryLogRecordKind.NameValueList); - Write(nameValueIndexListBuffer.Count); - for (int i = 0; i < nameValueListBuffer.Count; i++) + using (var _ = RedirectWritesToDifferentWriter(nameValueListBw, binaryWriter)) { - var kvp = nameValueIndexListBuffer[i]; - Write(kvp.Key); - Write(kvp.Value); + Write(nameValueIndexListBuffer.Count); + for (int i = 0; i < nameValueListBuffer.Count; i++) + { + var kvp = nameValueIndexListBuffer[i]; + Write(kvp.Key); + Write(kvp.Value); + } } + + FlushRecordToFinalStream(BinaryLogRecordKind.NameValueList, nameValueListStream); } /// @@ -1124,7 +1122,7 @@ private void Write(BinaryLogRecordKind kind) Write((int)kind); } - private void Write(int value) + internal void Write(int value) { BinaryWriterExtensions.Write7BitEncodedInt(binaryWriter, value); } @@ -1139,9 +1137,12 @@ private void Write(byte[] bytes) binaryWriter.Write(bytes); } - private void Write(Stream stream) + private void WriteToOriginalStream(Stream stream) { - stream.CopyTo(binaryWriter.BaseStream); + // WARNING: avoid calling binaryWriter.BaseStream here + // as it will flush the underlying stream - since that is a + // BufferedStream it will make buffering nearly useless + stream.CopyTo(originalStream); } private void Write(byte b) @@ -1198,7 +1199,7 @@ private void WriteDeduplicatedString(string text) return (recordId, hash); } - private void WriteStringRecord(string text) + internal void WriteStringRecord(string text) { using var redirectionScope = RedirectWritesToOriginalWriter(); diff --git a/src/Build/Logging/BinaryLogger/IBuildEventArgsReaderNotifications.cs b/src/Build/Logging/BinaryLogger/IBuildEventArgsReaderNotifications.cs deleted file mode 100644 index 415bd7c71fd..00000000000 --- a/src/Build/Logging/BinaryLogger/IBuildEventArgsReaderNotifications.cs +++ /dev/null @@ -1,13 +0,0 @@ -// Licensed to the .NET Foundation under one or more agreements. -// The .NET Foundation licenses this file to you under the MIT license. - -namespace Microsoft.Build.Logging -{ - /// - /// An interface for notifications from BuildEventArgsReader - /// - public interface IBuildEventArgsReaderNotifications : IBuildEventStringsReader - { - /* For future use */ - } -} diff --git a/src/Build/Logging/BinaryLogger/IBuildEventStringsReader.cs b/src/Build/Logging/BinaryLogger/IBuildEventStringsReader.cs deleted file mode 100644 index e9e7651ee78..00000000000 --- a/src/Build/Logging/BinaryLogger/IBuildEventStringsReader.cs +++ /dev/null @@ -1,26 +0,0 @@ -// Licensed to the .NET Foundation under one or more agreements. -// The .NET Foundation licenses this file to you under the MIT license. - -using System; - -namespace Microsoft.Build.Logging -{ - /// - /// An interface for notifications about reading strings from the binary log. - /// - public interface IBuildEventStringsReader - { - /// - /// An event that allows the subscriber to be notified when a string is read from the binary log. - /// Subscriber may adjust the string by setting property. - /// The passed event arg can be reused and should not be stored. - /// - public event Action? StringReadDone; - - /// - /// An event that allows the caller to be notified when a string is encountered in the binary log. - /// BinaryReader passed in ctor is at the beginning of the string at this point. - /// - public event Action? StringEncountered; - } -} diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/ArchiveFile.cs b/src/Build/Logging/BinaryLogger/Postprocessing/ArchiveFile.cs new file mode 100644 index 00000000000..ec8ba12c8b1 --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/ArchiveFile.cs @@ -0,0 +1,91 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.IO; +using System.IO.Compression; +using System.Text; +using Microsoft.Build.Shared; + +namespace Microsoft.Build.Logging +{ + /// + /// An object model for binlog embedded files. + /// Used in event. + /// + public abstract class ArchiveData : IDisposable + { + private protected ArchiveData(string fullPath) => FullPath = fullPath; + + /// + /// Full path of the original file before it was put in the embedded archive. + /// + public string FullPath { get; } + + /// + /// Materializes the whole content of the embedded file in memory as a string. + /// + /// + public abstract ArchiveFile ToArchiveFile(); + + public virtual void Dispose() + { } + } + + /// + /// Fully materialized (in-memory) embedded file. + /// Easier to work with (the content is expressed in a single string), but more memory greedy. + /// + public sealed class ArchiveFile : ArchiveData + { + public ArchiveFile(string fullPath, string content) + : base(fullPath) + => Content = content; + + /// + /// The content of the original file. + /// + public string Content { get; } + + /// + public override ArchiveFile ToArchiveFile() + => this; + } + + /// + /// Lazy (streaming) embedded file. + /// Might be favorable for large files, as it doesn't materialize the whole content in memory. + /// + public sealed class ArchiveStream : ArchiveData + { + public ArchiveStream(string fullPath, StreamReader contentReader) + : base(fullPath) + => ContentReader = contentReader; + + /// + /// Stream over the content of the archived file. + /// + public StreamReader ContentReader { get; } + + /// + /// Creates an externally exposable embedded file representation from a (which is an implementation detail currently). + /// + /// + /// + internal static ArchiveStream From(ZipArchiveEntry entry) + { + return new ArchiveStream(entry.FullName, new StreamReader(entry.Open())); + } + + /// + public override ArchiveFile ToArchiveFile() + { + var content = ContentReader.ReadToEnd(); + ContentReader.Dispose(); + return new ArchiveFile(FullPath, content); + } + + public override void Dispose() + => ContentReader.Dispose(); + } +} diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/ArchiveFileEventArgs.cs b/src/Build/Logging/BinaryLogger/Postprocessing/ArchiveFileEventArgs.cs new file mode 100644 index 00000000000..9dc2b2e42a1 --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/ArchiveFileEventArgs.cs @@ -0,0 +1,20 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; + +namespace Microsoft.Build.Logging; + +/// +/// Event arguments for event. +/// +public sealed class ArchiveFileEventArgs : EventArgs +{ + public ArchiveData ArchiveData { get; set; } + + public ArchiveFileEventArgs(ArchiveData archiveData) => ArchiveData = archiveData; + + // Intentionally not exposing this publicly (e.g. as IDisposable implementation) + // as we don't want to user to be bothered with ownership and disposing concerns. + internal void Dispose() => ArchiveData.Dispose(); +} diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/ArchiveFileEventArgsExtensions.cs b/src/Build/Logging/BinaryLogger/Postprocessing/ArchiveFileEventArgsExtensions.cs new file mode 100644 index 00000000000..985e761411a --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/ArchiveFileEventArgsExtensions.cs @@ -0,0 +1,52 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; + +namespace Microsoft.Build.Logging; + +public static class ArchiveFileEventArgsExtensions +{ + /// + /// Helper method that allows to subscribe to event via event handler. + /// + /// This applies only when subscriber is OK with greedy reading entire content of the file and is interested only in the individual strings (e.g. for sensitive data redaction purposes), + /// without distinction what each individual string means (e.g. they do not care about distinction between path and content or between individual files - they just need all textual data). + /// + /// + /// + /// private void OnStringReadDone(StringReadEventArgs e) + /// { + /// e.StringToBeUsed = e.StringToBeUsed.Replace("foo", "bar"); + /// } + /// + /// private void SubscribeToEvents() + /// { + /// reader.StringReadDone += OnStringReadDone; + /// reader.ArchiveFileEncountered += ((Action<StringReadEventArgs>)OnStringReadDone).ToArchiveFileHandler(); + /// } + /// + /// + /// + public static Action ToArchiveFileHandler(this Action stringHandler) + { + return args => + { + var archiveFile = args.ArchiveData.ToArchiveFile(); + var pathArgs = new StringReadEventArgs(archiveFile.FullPath); + stringHandler(pathArgs); + var contentArgs = new StringReadEventArgs(archiveFile.Content); + stringHandler(contentArgs); + + if(pathArgs.StringToBeUsed != pathArgs.OriginalString || + contentArgs.StringToBeUsed != contentArgs.OriginalString) + { + args.ArchiveData = new ArchiveFile(pathArgs.StringToBeUsed, contentArgs.StringToBeUsed); + } + else + { + args.ArchiveData = archiveFile; + } + }; + } +} diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/BinaryLogReaderErrorEventArgs.cs b/src/Build/Logging/BinaryLogger/Postprocessing/BinaryLogReaderErrorEventArgs.cs new file mode 100644 index 00000000000..adad3e7d363 --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/BinaryLogReaderErrorEventArgs.cs @@ -0,0 +1,49 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; + +namespace Microsoft.Build.Logging +{ + /// + /// Materializes the error message. + /// Until it's called the error message is not materialized and no string allocations are made. + /// + /// The error message. + internal delegate string FormatErrorMessage(); + + /// + /// An event args for event. + /// + public sealed class BinaryLogReaderErrorEventArgs : EventArgs + { + private readonly FormatErrorMessage _formatErrorMessage; + + internal BinaryLogReaderErrorEventArgs( + ReaderErrorType errorType, + BinaryLogRecordKind recordKind, + FormatErrorMessage formatErrorMessage) + { + ErrorType = errorType; + RecordKind = recordKind; + _formatErrorMessage = formatErrorMessage; + } + + /// + /// Type of the error that occurred during reading. + /// + public ReaderErrorType ErrorType { get; } + + /// + /// Kind of the record that encountered the error. + /// + public BinaryLogRecordKind RecordKind { get; } + + /// + /// Materializes the error message. + /// Until it's called the error message is not materialized and no string allocations are made. + /// + /// The error message. + public string GetFormattedMessage() => _formatErrorMessage(); + } +} diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/CleanupScope.cs b/src/Build/Logging/BinaryLogger/Postprocessing/CleanupScope.cs new file mode 100644 index 00000000000..3045f914fe7 --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/CleanupScope.cs @@ -0,0 +1,15 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; + +namespace Microsoft.Build.Logging; + +internal readonly struct CleanupScope : IDisposable +{ + private readonly Action _disposeAction; + + public CleanupScope(Action disposeAction) => _disposeAction = disposeAction; + + public void Dispose() => _disposeAction(); +} diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/EmbeddedContentEventArgs.cs b/src/Build/Logging/BinaryLogger/Postprocessing/EmbeddedContentEventArgs.cs new file mode 100644 index 00000000000..123d927dd12 --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/EmbeddedContentEventArgs.cs @@ -0,0 +1,20 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.IO; + +namespace Microsoft.Build.Logging +{ + internal sealed class EmbeddedContentEventArgs : EventArgs + { + public EmbeddedContentEventArgs(BinaryLogRecordKind contentKind, Stream contentStream) + { + ContentKind = contentKind; + ContentStream = contentStream; + } + + public BinaryLogRecordKind ContentKind { get; } + public Stream ContentStream { get; } + } +} diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/IBuildEventArgsReaderNotifications.cs b/src/Build/Logging/BinaryLogger/Postprocessing/IBuildEventArgsReaderNotifications.cs new file mode 100644 index 00000000000..aee71562898 --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/IBuildEventArgsReaderNotifications.cs @@ -0,0 +1,50 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; + +namespace Microsoft.Build.Logging +{ + /// + /// An interface for notifications from BuildEventArgsReader + /// + public interface IBuildEventArgsReaderNotifications + { + /// + /// An event that allows the subscriber to be notified when a string is read from the binary log. + /// Subscriber may adjust the string by setting property. + /// The passed event arg can be reused and should not be stored. + /// + event Action? StringReadDone; + + /// + /// An event that allows the caller to be notified when an embedded file is encountered in the binary log. + /// When subscriber is OK with greedy reading entire content of the file and is interested only in the individual strings (e.g. for sensitive data redaction purposes), + /// it can simplify subscribing to this event, by using handler with same signature as handler for and wrapping it via + /// extension. + /// + /// + /// + /// private void OnStringReadDone(StringReadEventArgs e) + /// { + /// e.StringToBeUsed = e.StringToBeUsed.Replace("foo", "bar"); + /// } + /// + /// private void SubscribeToEvents() + /// { + /// reader.StringReadDone += OnStringReadDone; + /// reader.ArchiveFileEncountered += ((Action<StringReadEventArgs>)OnStringReadDone).ToArchiveFileHandler(); + /// } + /// + /// + event Action? ArchiveFileEncountered; + + /// + /// Receives recoverable errors during reading. + /// Communicates type of the error, kind of the record that encountered the error and the message detailing the error. + /// In case of this is raised before returning the structured representation of a build event + /// that has some extra unknown data in the binlog. In case of other error types this event is raised and the offending build event is skipped and not returned. + /// + event Action? RecoverableReadError; + } +} diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/ReaderErrorType.cs b/src/Build/Logging/BinaryLogger/Postprocessing/ReaderErrorType.cs new file mode 100644 index 00000000000..5bce4a50935 --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/ReaderErrorType.cs @@ -0,0 +1,29 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +namespace Microsoft.Build.Logging; + +/// +/// Type of the error that occurred during reading. +/// +public enum ReaderErrorType +{ + /// + /// The encountered event is completely unknown to the reader. It cannot interpret any part of it. + /// + UnknownEventType, + + /// + /// The encountered event is known to the reader and reader is able to read the event as it knows it. + /// However there are some extra data (append only extension to the event in future version), that reader cannot interpret, + /// it can only skip it. + /// + UnknownEventData, + + /// + /// The encountered event type is known to the reader, but the reader cannot interpret the data of the event. + /// This is probably caused by an event definition changing more than just adding fields. + /// The reader can only skip the event in full. + /// + UnknownFormatOfEventData, +} diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/StreamExtensions.cs b/src/Build/Logging/BinaryLogger/Postprocessing/StreamExtensions.cs new file mode 100644 index 00000000000..2993b3953c1 --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/StreamExtensions.cs @@ -0,0 +1,102 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Buffers; +using System.Diagnostics; +using System.IO; +using Microsoft.Build.Shared; + +namespace Microsoft.Build.Logging +{ + internal static class StreamExtensions + { + private static bool CheckIsSkipNeeded(long bytesCount) + { + if (bytesCount is < 0 or > int.MaxValue) + { + throw new ArgumentOutOfRangeException(nameof(bytesCount), ResourceUtilities.FormatResourceStringStripCodeAndKeyword("Binlog_StreamUtils_UnsupportedSkipOffset", + bytesCount)); + } + + return bytesCount > 0; + } + + public static long SkipBytes(this Stream stream, long bytesCount) + { + if (!CheckIsSkipNeeded(bytesCount)) + { + return 0; + } + + byte[] buffer = ArrayPool.Shared.Rent(4096); + using var _ = new CleanupScope(() => ArrayPool.Shared.Return(buffer)); + return SkipBytes(stream, bytesCount, buffer); + } + + public static long SkipBytes(this Stream stream, long bytesCount, byte[] buffer) + { + if (!CheckIsSkipNeeded(bytesCount)) + { + return 0; + } + + long totalRead = 0; + while (totalRead < bytesCount) + { + int read = stream.Read(buffer, 0, (int)Math.Min(bytesCount - totalRead, buffer.Length)); + if (read == 0) + { + throw new InvalidDataException("Unexpected end of stream."); + } + + totalRead += read; + } + + return totalRead; + } + + public static byte[] ReadToEnd(this Stream stream) + { + if (stream.TryGetLength(out long length)) + { + BinaryReader reader = new(stream); + return reader.ReadBytes((int)length); + } + + using var ms = new MemoryStream(); + stream.CopyTo(ms); + return ms.ToArray(); + } + + public static bool TryGetLength(this Stream stream, out long length) + { + try + { + length = stream.Length; + return true; + } + catch (NotSupportedException) + { + length = 0; + return false; + } + } + + public static Stream ToReadableSeekableStream(this Stream stream) + { + return TransparentReadStream.EnsureSeekableStream(stream); + } + + /// + /// Creates bounded read-only, forward-only view over an underlying stream. + /// + /// + /// + /// + public static Stream Slice(this Stream stream, long length) + { + return new SubStream(stream, length); + } + } +} diff --git a/src/Build/Logging/BinaryLogger/StringReadEventArgs.cs b/src/Build/Logging/BinaryLogger/Postprocessing/StringReadEventArgs.cs similarity index 90% rename from src/Build/Logging/BinaryLogger/StringReadEventArgs.cs rename to src/Build/Logging/BinaryLogger/Postprocessing/StringReadEventArgs.cs index e2a4c83d3cb..909cec443eb 100644 --- a/src/Build/Logging/BinaryLogger/StringReadEventArgs.cs +++ b/src/Build/Logging/BinaryLogger/Postprocessing/StringReadEventArgs.cs @@ -6,7 +6,7 @@ namespace Microsoft.Build.Logging { /// - /// An event args for callback. + /// An event args for callback. /// public sealed class StringReadEventArgs : EventArgs { diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/SubStream.cs b/src/Build/Logging/BinaryLogger/Postprocessing/SubStream.cs new file mode 100644 index 00000000000..ff5caf9bfdf --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/SubStream.cs @@ -0,0 +1,55 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.IO; +using Microsoft.Build.Shared; + +namespace Microsoft.Build.Logging +{ + /// + /// Bounded read-only, forward-only view over an underlying stream. + /// + internal sealed class SubStream : Stream + { + // Do not Dispose/Close on Dispose/Close !! + private readonly Stream _stream; + private readonly long _length; + private long _position; + + public SubStream(Stream stream, long length) + { + _stream = stream; + _length = length; + + if (!stream.CanRead) + { + throw new NotSupportedException(ResourceUtilities.GetResourceString("Binlog_StreamUtils_MustBeReadable")); + } + } + + public bool IsAtEnd => _position >= _length; + + public override bool CanRead => true; + + public override bool CanSeek => false; + + public override bool CanWrite => false; + + public override long Length => _length; + + public override long Position { get => _position; set => throw new NotImplementedException(); } + + public override void Flush() { } + public override int Read(byte[] buffer, int offset, int count) + { + count = Math.Min((int)Math.Max(Length - _position, 0), count); + int read = _stream.Read(buffer, offset, count); + _position += read; + return read; + } + public override long Seek(long offset, SeekOrigin origin) => throw new NotImplementedException(); + public override void SetLength(long value) => throw new NotImplementedException(); + public override void Write(byte[] buffer, int offset, int count) => throw new NotImplementedException(); + } +} diff --git a/src/Build/Logging/BinaryLogger/Postprocessing/TransparentReadStream.cs b/src/Build/Logging/BinaryLogger/Postprocessing/TransparentReadStream.cs new file mode 100644 index 00000000000..4dd9afa0300 --- /dev/null +++ b/src/Build/Logging/BinaryLogger/Postprocessing/TransparentReadStream.cs @@ -0,0 +1,114 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.IO; +using Microsoft.Build.Shared; + +namespace Microsoft.Build.Logging +{ + /// + /// A wrapper stream that allows position tracking and forward seeking. + /// + internal sealed class TransparentReadStream : Stream + { + private readonly Stream _stream; + private long _position; + private long _maxAllowedPosition = long.MaxValue; + + public static Stream EnsureSeekableStream(Stream stream) + { + if (stream.CanSeek) + { + return stream; + } + + if (!stream.CanRead) + { + throw new InvalidOperationException(ResourceUtilities.GetResourceString("Binlog_StreamUtils_MustBeReadable")); + } + + return new TransparentReadStream(stream); + } + + public static TransparentReadStream EnsureTransparentReadStream(Stream stream) + { + if (stream is TransparentReadStream transparentReadStream) + { + return transparentReadStream; + } + + if (!stream.CanRead) + { + throw new InvalidOperationException(ResourceUtilities.GetResourceString("Binlog_StreamUtils_MustBeReadable")); + } + + return new TransparentReadStream(stream); + } + + private TransparentReadStream(Stream stream) + { + _stream = stream; + } + + public int? BytesCountAllowedToRead + { + set { _maxAllowedPosition = value.HasValue ? _position + value.Value : long.MaxValue; } + } + + // if we haven't constrained the allowed read size - do not report it being unfinished either. + public int BytesCountAllowedToReadRemaining => + _maxAllowedPosition == long.MaxValue ? 0 : (int)(_maxAllowedPosition - _position); + + public override bool CanRead => _stream.CanRead; + public override bool CanSeek => true; + public override bool CanWrite => false; + public override long Length => _stream.Length; + public override long Position + { + get => _position; + set => this.SkipBytes(value - _position); + } + + public override void Flush() + { + _stream.Flush(); + } + + public override int Read(byte[] buffer, int offset, int count) + { + if (_position + count > _maxAllowedPosition) + { + count = (int)(_maxAllowedPosition - _position); + } + + int cnt = _stream.Read(buffer, offset, count); + _position += cnt; + return cnt; + } + + public override long Seek(long offset, SeekOrigin origin) + { + if (origin != SeekOrigin.Current) + { + throw new NotSupportedException(ResourceUtilities.GetResourceString("Binlog_StreamUtils_SeekNonOrigin")); + } + + this.SkipBytes(offset); + + return _position; + } + + public override void SetLength(long value) + { + throw new NotSupportedException(ResourceUtilities.GetResourceString("Binlog_StreamUtils_SetLengthUnsupported")); + } + + public override void Write(byte[] buffer, int offset, int count) + { + throw new NotSupportedException(ResourceUtilities.GetResourceString("Binlog_StreamUtils_WriteUnsupported")); + } + + public override void Close() => _stream.Close(); + } +} diff --git a/src/Build/Logging/BinaryLogger/ProjectImportsCollector.cs b/src/Build/Logging/BinaryLogger/ProjectImportsCollector.cs index 27ededae8cc..536d7f9ed48 100644 --- a/src/Build/Logging/BinaryLogger/ProjectImportsCollector.cs +++ b/src/Build/Logging/BinaryLogger/ProjectImportsCollector.cs @@ -8,8 +8,7 @@ using System.Text; using System.Threading.Tasks; using Microsoft.Build.Shared; - -#nullable disable +using Microsoft.Build.Shared.FileSystem; namespace Microsoft.Build.Logging { @@ -21,10 +20,11 @@ namespace Microsoft.Build.Logging /// internal class ProjectImportsCollector { - private Stream _fileStream; - private ZipArchive _zipArchive; - - public string ArchiveFilePath { get; } + private Stream? _fileStream; + private ZipArchive? _zipArchive; + private readonly string _archiveFilePath; + private readonly bool _runOnBackground; + private const string DefaultSourcesArchiveExtension = ".ProjectImports.zip"; /// /// Avoid visiting each file more than once. @@ -34,12 +34,29 @@ internal class ProjectImportsCollector // this will form a chain of file write tasks, running sequentially on a background thread private Task _currentTask = Task.CompletedTask; - public ProjectImportsCollector(string logFilePath, bool createFile, string sourcesArchiveExtension = ".ProjectImports.zip") + internal static void FlushBlobToFile( + string logFilePath, + Stream contentStream) + { + string archiveFilePath = GetArchiveFilePath(logFilePath, DefaultSourcesArchiveExtension); + + using var fileStream = new FileStream(archiveFilePath, FileMode.Create, FileAccess.ReadWrite, FileShare.Delete); + contentStream.CopyTo(fileStream); + } + + // Archive file will be stored alongside the binlog + private static string GetArchiveFilePath(string logFilePath, string sourcesArchiveExtension) + => Path.ChangeExtension(logFilePath, sourcesArchiveExtension); + + public ProjectImportsCollector( + string logFilePath, + bool createFile, + string sourcesArchiveExtension = DefaultSourcesArchiveExtension, + bool runOnBackground = true) { if (createFile) { - // Archive file will be stored alongside the binlog - ArchiveFilePath = Path.ChangeExtension(logFilePath, sourcesArchiveExtension); + _archiveFilePath = GetArchiveFilePath(logFilePath, sourcesArchiveExtension); } else { @@ -50,16 +67,16 @@ public ProjectImportsCollector(string logFilePath, bool createFile, string sourc } // Archive file will be temporarily stored in MSBuild cache folder and deleted when no longer needed - ArchiveFilePath = Path.Combine( + _archiveFilePath = Path.Combine( cacheDirectory, - Path.ChangeExtension( + GetArchiveFilePath( Path.GetFileName(logFilePath), sourcesArchiveExtension)); } try { - _fileStream = new FileStream(ArchiveFilePath, FileMode.Create, FileAccess.ReadWrite, FileShare.Delete); + _fileStream = new FileStream(_archiveFilePath, FileMode.Create, FileAccess.ReadWrite, FileShare.Delete); _zipArchive = new ZipArchive(_fileStream, ZipArchiveMode.Create); } catch @@ -69,49 +86,67 @@ public ProjectImportsCollector(string logFilePath, bool createFile, string sourc _fileStream = null; _zipArchive = null; } + _runOnBackground = runOnBackground; + } + + public void AddFile(string? filePath) + { + AddFileHelper(filePath, AddFileCore); } - public void AddFile(string filePath) + public void AddFileFromMemory( + string? filePath, + string data, + DateTimeOffset? entryCreationStamp = null, + bool makePathAbsolute = true) + { + AddFileHelper(filePath, path => + AddFileFromMemoryCore(path, data, makePathAbsolute, entryCreationStamp)); + } + + public void AddFileFromMemory( + string? filePath, + Stream data, + DateTimeOffset? entryCreationStamp = null, + bool makePathAbsolute = true) + { + AddFileHelper(filePath, path => AddFileFromMemoryCore(path, data, makePathAbsolute, entryCreationStamp)); + } + + private void AddFileHelper( + string? filePath, + Action addFileWorker) { if (filePath != null && _fileStream != null) { lock (_fileStream) { - // enqueue the task to add a file and return quickly - // to avoid holding up the current thread - _currentTask = _currentTask.ContinueWith(t => + if (_runOnBackground) { - try - { - AddFileCore(filePath); - } - catch - { - } - }, TaskScheduler.Default); + // enqueue the task to add a file and return quickly + // to avoid holding up the current thread + _currentTask = _currentTask.ContinueWith( + t => { TryAddFile(); }, + TaskScheduler.Default); + } + else + { + TryAddFile(); + } } } - } - public void AddFileFromMemory(string filePath, string data) - { - if (filePath != null && data != null && _fileStream != null) + bool TryAddFile() { - lock (_fileStream) + try { - // enqueue the task to add a file and return quickly - // to avoid holding up the current thread - _currentTask = _currentTask.ContinueWith(t => - { - try - { - AddFileFromMemoryCore(filePath, data); - } - catch - { - } - }, TaskScheduler.Default); + addFileWorker(filePath); + return true; } + catch + { } + + return false; } } @@ -122,61 +157,82 @@ public void AddFileFromMemory(string filePath, string data) private void AddFileCore(string filePath) { // quick check to avoid repeated disk access for Exists etc. - if (_processedFiles.Contains(filePath)) + if (!ShouldAddFile(ref filePath, true, true)) { return; } - if (!File.Exists(filePath)) + using FileStream content = new FileStream(filePath, FileMode.Open, FileAccess.Read, FileShare.Read | FileShare.Delete); + AddFileData(filePath, content, null); + } + + /// + /// This method doesn't need locking/synchronization because it's only called + /// from a task that is chained linearly + /// + private void AddFileFromMemoryCore(string filePath, string data, bool makePathAbsolute, DateTimeOffset? entryCreationStamp) + { + // quick check to avoid repeated disk access for Exists etc. + if (!ShouldAddFile(ref filePath, false, makePathAbsolute)) { - _processedFiles.Add(filePath); return; } - filePath = Path.GetFullPath(filePath); + using var content = new MemoryStream(Encoding.UTF8.GetBytes(data)); + AddFileData(filePath, content, entryCreationStamp); + } - // if the file is already included, don't include it again - if (!_processedFiles.Add(filePath)) + private void AddFileFromMemoryCore(string filePath, Stream data, bool makePathAbsolute, DateTimeOffset? entryCreationStamp) + { + // quick check to avoid repeated disk access for Exists etc. + if (!ShouldAddFile(ref filePath, false, makePathAbsolute)) { return; } - using FileStream content = new FileStream(filePath, FileMode.Open, FileAccess.Read, FileShare.Read | FileShare.Delete); - using Stream entryStream = OpenArchiveEntry(filePath); - content.CopyTo(entryStream); + AddFileData(filePath, data, entryCreationStamp); } - /// - /// This method doesn't need locking/synchronization because it's only called - /// from a task that is chained linearly - /// - private void AddFileFromMemoryCore(string filePath, string data) + private void AddFileData(string filePath, Stream data, DateTimeOffset? entryCreationStamp) + { + using Stream entryStream = OpenArchiveEntry(filePath, entryCreationStamp); + data.CopyTo(entryStream); + } + + private bool ShouldAddFile(ref string filePath, bool checkFileExistence, bool makeAbsolute) { // quick check to avoid repeated disk access for Exists etc. if (_processedFiles.Contains(filePath)) { - return; + return false; } - filePath = Path.GetFullPath(filePath); - - // if the file is already included, don't include it again - if (!_processedFiles.Add(filePath)) + if (checkFileExistence && !File.Exists(filePath)) { - return; + _processedFiles.Add(filePath); + return false; } - using (Stream entryStream = OpenArchiveEntry(filePath)) - using (var content = new MemoryStream(Encoding.UTF8.GetBytes(data))) + // Only make the path absolute if it's request. In the replay scenario, the file entries + // are read from zip archive - where ':' is stripped and path can then seem relative. + if (makeAbsolute) { - content.CopyTo(entryStream); + filePath = Path.GetFullPath(filePath); } + + // if the file is already included, don't include it again + return _processedFiles.Add(filePath); } - private Stream OpenArchiveEntry(string filePath) + private Stream OpenArchiveEntry(string filePath, DateTimeOffset? entryCreationStamp) { string archivePath = CalculateArchivePath(filePath); - var archiveEntry = _zipArchive.CreateEntry(archivePath); + var archiveEntry = _zipArchive!.CreateEntry(archivePath); + if (entryCreationStamp.HasValue) + { + archiveEntry.LastWriteTime = entryCreationStamp.Value; + } + return archiveEntry.Open(); } @@ -191,6 +247,27 @@ private static string CalculateArchivePath(string filePath) return archivePath; } + public void ProcessResult(Action consumeStream, Action onError) + { + Close(); + + // It is possible that the archive couldn't be created for some reason. + // Only embed it if it actually exists. + if (FileSystems.Default.FileExists(_archiveFilePath)) + { + using FileStream fileStream = File.OpenRead(_archiveFilePath); + + if (fileStream.Length > int.MaxValue) + { + onError(ResourceUtilities.GetResourceString("Binlog_ImportFileSizeError")); + } + else + { + consumeStream(fileStream); + } + } + } + public void Close() { // wait for all pending file writes to complete @@ -208,5 +285,11 @@ public void Close() _fileStream = null; } } + + public void DeleteArchive() + { + Close(); + File.Delete(_archiveFilePath); + } } } diff --git a/src/Build/Microsoft.Build.csproj b/src/Build/Microsoft.Build.csproj index b2b662710ef..ebcff02886d 100644 --- a/src/Build/Microsoft.Build.csproj +++ b/src/Build/Microsoft.Build.csproj @@ -1,4 +1,4 @@ - + @@ -160,10 +160,6 @@ - - - - @@ -533,6 +529,8 @@ + + diff --git a/src/Build/Resources/Strings.resx b/src/Build/Resources/Strings.resx index 17663002579..8a4c054002c 100644 --- a/src/Build/Resources/Strings.resx +++ b/src/Build/Resources/Strings.resx @@ -1363,7 +1363,7 @@ Errors: {3} {StrBegin="MSB4068: "} - MSB4235: The log file format version is {0}, whereas this version of MSBuild only supports versions up to {1}. + MSB4235: The log file format version is {0} with minimum required reader version {1}, whereas this version of MSBuild only supports versions up to {2}. {StrBegin="MSB4235: "} @@ -2015,6 +2015,75 @@ Utilization: {0} Average Utilization: {1:###.0} Reporting file accesses is only currently supported using the x64 flavor of MSBuild. + + Structured events and raw events cannot be replayed at the same time. + + + No subscribers for any events. + + + Version info not yet initialized. Replay must be called first. + + + Subscription to RecoverableReadError is mandatory during forward compatible reading. + + + Imported files archive exceeded 2GB limit and it's not embedded. + + + Forward compatible reading is not supported for file format version {0} (needs >= 18). + + LOCALIZATION: {0} is an integer number denoting version. + + + + Skipping the record. + + + BuildEvent record number {0} (serialized size: {1}) attempted to perform disallowed reads (details: {2}: {3}). + + LOCALIZATION: {0} is an integer number denoting order. {1} is an integer denoting size. {2} is an exception type and {3} the exception message string. + + + + BuildEvent record number {0} (serialized size: {1}) is of unsupported type: {2}. + + LOCALIZATION: {0} is an integer number denoting order. {1} is an integer denoting size. {2} is a string or integer value indicating type. + + + + BuildEvent record number {0} was expected to read exactly {1} bytes from the stream, but read {2} instead. + + LOCALIZATION: {0} is an integer number denoting order. {1} is an integer denoting size. {2} is an integer value indicating number of bytes. + + + + Content already acquired as StreamReader via GetContentReader. + + + Content already acquired as string via GetContent or initialized as string only. + + + ArchiveFile was obtained, but the final edited version was not set. + + + Stream must be readable. + + + Only seeking from SeekOrigin.Current is supported. + + + Changing the stream length is not supported. + + + Writing is not supported. + + + Attempt to skip {0} bytes, only non-negative offset up to int.MaxValue is allowed. + + LOCALIZATION: {0} is integer number denoting number of bytes. 'int.MaxValue' should not be translated. + +