Add support for forward compatible binlog format

[JanKrivanek]

Context

Complement to MSBuild PR https://github.com/dotnet/msbuild/pull/9307 This introduces capability to understand the new log format that contains event offsets - with those, reader can detect issues with individual events and choose how to handle those (recover/skip/fail). Logs now as well contain the minimum needed version of reader - to capture situations where new log format changes beyond comprehension ability of particular reader version.

User is still given the ability to decide the level of compatibility and see the resulting stats of compatability issues.

Further info

Some perf stats: https://github.com/JanKrivanek/msbuild/pull/1 MSBuild parent bug: https://github.com/dotnet/msbuild/issues/9261

UX v2

GUI

CLI

Unchanged

API

The Serialization.Read method will accept optional ReaderSettings with UnknownDataBehavior parameter (of an enum type with the same name). If not specified, the compatibility issues are summarized in a single synthetized Error node on the Build.

   // This will work just fine on future versions of binlog
   var build = Serialization.Read(logPath);

---

stop reading from here below - captures historic evolution of the PR that is not part of the final version

UX (reverted)

GUI

Cancel:

OK:

File -> Stats (upon expanding all collapsed nodes):

CLI

API

The Serialization.Read method will accept optional IForwardCompatibilityReadSettings - if not specified, the legacy behavior (exception on newer format) is preserved:

   // This will throw on future version of logs
   var build = Serialization.Read(logPath);

To leverage the new behavior - one need to specify the forward compatibility handler - e.g.:

   // This will allow processing future version of logs and will store the reading errors summary in build.RecoverableReadingErrors
   var build = Serialization.Read(logPath, progress: null, forwardCompatibilitySettings: ((AllowForwardCompatibilityDelegate)(_ => true)).WithDefaultHandler());

The handler allows granular control of opt-ing into the forward compatibility behavior (in case incompatibility is encountered) and handling the individual reading errors. For summary the reading errors are stored in Build.RecoverableReadingErrors property.

Alternatively a ForwardCompatibilityReadingHandler from binlogtool can be used:

  ForwardCompatibilityReadingHandler compatHandler = new ForwardCompatibilityReadingHandler();
  compatHandler.SetMode(ForwardCompatibilityReadingHandler.Mode.LogErrorsDetailed);
  var build = compatHandler.ReadBuild(logPath);
  // optional summarization of errors
  compatHandler.HandleBuildResults(build, Console.Error);

My initial gut reaction is that forward compat should be the default for all readers, and if there are compat issues we can emit a synthetic BuildErrorEventArgs or BuildWarningEventArgs. Maybe consumers could tweak whether they want to see an error, a warning, a message or nothing at all for compat issues.

So I'd remove things like ForwardCompatibilityExplicitlyConfigured, -fwd, and related things and keep it as simple as possible. Since the current behavior is we throw an exception, literally anything else is an improvement. I'd like users to update to this version of the NuGet and not have to change anything and be automatically opted in.

The new GUI seems nice, but I'd think it's an overkill (just display a synthetic Error or Warning like I suggest above at the very top of the tree). But since you've already built it, might as well leave it I guess. I think users won't see this often anyway, since the viewer updates when it starts.

[KirillOsenkov]

Overall everything looks good. After all the changes on the MSBuild side are finalized, do the same changes here and then we can merge this one first. Then I'll publish the viewer and the NuGet and the CLI tools, and then we can merge the MSBuild side.

One concern is that we should ensure the Avalonia version still works. I don't think it needs the GUI or the stats, but at least opening binlogs from the future should work fine.

Ideally if you switch to emitting synthetic errors/warnings instead of custom data on the build or via events, both WPF and Avalonia will get it for free. Just remember to maybe only emit a single error per record type (otherwise we risk reporting thousands of identical errors).

My preferred experience for the consumers of the MSBuild.StructuredLogger NuGet package is that they'll update to the new version and they don't have to change anything else or consume any other API. If they read a binlog from the future with unknown records, emit BuildErrorEventArgs and let them handle it they way they want. If they display the errors someplace, they will see the errors and know to update the NuGet to latest. If they don't see the errors, they probably don't care either, in this way we can just be silent. They could opt in into throwing when the file format is from the future if they want to be notified.

This was a gargantuan amount of work, thanks a ton for driving this!

Don't worry about the CLI, this stuff is still all experimental. Anything is fine.

[JanKrivanek]

My initial gut reaction is that forward compat should be the default for all readers, and if there are compat issues we can emit a synthetic BuildErrorEventArgs or BuildWarningEventArgs. Maybe consumers could tweak whether they want to see an error, a warning, a message or nothing at all for compat issues.

So I'd remove things like ForwardCompatibilityExplicitlyConfigured, -fwd, and related things and keep it as simple as possible. Since the current behavior is we throw an exception, literally anything else is an improvement. I'd like users to update to this version of the NuGet and not have to change anything and be automatically opted in.

The new GUI seems nice, but I'd think it's an overkill (just display a synthetic Error or Warning like I suggest above at the very top of the tree). But since you've already built it, might as well leave it I guess. I think users won't see this often anyway, since the viewer updates when it starts.

I just wanted to flash something e-2-e to have easier discussion over it. No feelings attached to any of it - any of the code can go :-) I like the suggestion with the synthetic error/warning - lm try that. Making it deafult would make things easier.

Btw. I marked MSBuild changes as not mergable - until new viewer and binlogtools are published. Otherwise it's ready to go - but if you'd have any suggestions or concerns there, definitely still easy to make changes.

[KirillOsenkov]

I left some comments on the MSBuild change - did you see? Nothing critical but some might be beneficial.

[JanKrivanek]

@KirillOsenkov - btw. I noticed that replaying binlog in the 'raw' mode is slower and leads to bigger resulting file than with structured replay. After uncompressing the results are ideticall, but this is still undesired and bit unexpected (contrary to my initiall measurements) - so please hold on with merging - I want to first rootcause that.

[JanKrivanek]

@KirillOsenkov - btw. I noticed that replaying binlog in the 'raw' mode is slower and leads to bigger resulting file than with structured replay. After uncompressing the results are ideticall, but this is still undesired and bit unexpected (contrary to my initiall measurements) - so please hold on with merging - I want to first rootcause that.

tl;dr;: Fixed :tada: (after long long long evening :-))

1.0.9 (previous released) mean redact time for OrchardCore binlog: 00:00:22.1181747 Current version mean redact time: 00:00:08.7203408

1.0.9 (previous released) mean log replay time of raw events for OrchardCore binlog: 00:00:22.4146649 Current version mean log replay time of raw events: 00:00:04.9658039

The issue was hidden in the superfluous flushing of the BufferedStream caused by calling BinaryWriter.BaseStream (that leads to Flush).

[KirillOsenkov]

I published https://www.nuget.org/packages/binlogtool/1.0.10 with the latest main branch that includes this PR

[KirillOsenkov]

Published https://www.nuget.org/packages/MSBuild.StructuredLogger/2.2.155 as well, @jaredpar if you're feeling adventurous maybe update the package to 2.2.155 and then when MSBuild increments the file format version to 18 hopefully it'll just work and you won't have a build break.

[KirillOsenkov]

Published viewer update https://github.com/KirillOsenkov/MSBuildStructuredLog/releases/tag/v2.2.155