Skip to content

Use MSBuild Logging APIs for Task output instead of StdOut #933

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 41 commits into
base: main
Choose a base branch
from

Conversation

baronfel
Copy link
Member

Fixes #712
Fixes #616

This is a refresh of #730 that I've gotten the tests to green up on. Along the way I think I've also addressed #616, which was a consequence of way the dependencies of the task were initialized in the .NET task.

Since the majority of the tool uses Serilog, the strategy here is to integrate MSBuild's logging APIs into Serilog's logging configuration where possible. This means, broadly, two things:

  • creating and using an MSBuild Logger that converts Serilog's messages to calls to the TaskLoggingHelper's logging methods
  • ensuring that the Verbosity selected in the Task is used when configuring Serilog

Along the way, I've made it easier to test the post-conditions of the Task on both net472 and .NET.

@baronfel baronfel requested a review from a team as a code owner February 16, 2025 20:22
@baronfel
Copy link
Member Author

One big note - I'm using .NET SDK 9.0.200, where some of the Roslyn analyzers have been tweaked/fixed and so are reporting things that I had to fix in order to get the repo to compile.

@baronfel
Copy link
Member Author

baronfel commented Feb 17, 2025

I've attached a zipped binlog of the tool working with these changes. The detailed logs are in the binlog as expected.

sbom-pack.zip

To the end user, it looks like this:

> dotnet pack -bl
Restore complete (0.3s)
  sbom-tests succeeded with 1 warning(s) (5.6s) → bin\Release\net9.0\sbom-tests.dll
    E:\code\nuget-packages\microsoft.sbom.targets\3.1.1-preview.0.6\build\Microsoft.Sbom.Targets.targets(57,5): warning : Deleting pre-existing folder E:\Code\Scratch\sbom-tests\bin\Release\sbom-tests.1.0.0.4b5fcd2f.temp\_manifest as DeleteManifestDirIfPresent is 'true'.

Build succeeded with 1 warning(s) in 6.2s

I'd like to dig in a bit more about the spurious warning, I expect that's a mismatched warning regex or something on MSbuild's side.

This warning is coming from the SBOM targets - specifically from

log.Warning(
$"Deleting pre-existing folder {rootManifestFolderPath} as {Constants.DeleteManifestDirBoolVariableName}" +
$" is 'true'.");
. Is this really a warning? A user asked to delete a manifest if it was already there, and we're doing what they asked? This feels more like a debug/diagnostic to me. The big problem here is twofold:

  • many users run MSBuild with TreatWarningsAsErrors enabled
  • this particular warning, because it's coming from deep in the Serilog stack and not from direct use of MSBuild Logging APIs, doesn't have a Code associated with it, so users can't use MSbuild's knobs to disable/hide this warning when it does appear

@sfoslund
Copy link
Member

/azp run

@DaveTryon DaveTryon added the .NET Pull requests that update .net code label Feb 18, 2025
@DaveTryon
Copy link
Contributor

log.Warning(
$"Deleting pre-existing folder {rootManifestFolderPath} as {Constants.DeleteManifestDirBoolVariableName}" +
$" is 'true'.");

. Is this really a warning? A user asked to delete a manifest if it was already there, and we're doing what they asked? This feels more like a debug/diagnostic to me. The big problem here is twofold:

  • many users run MSBuild with TreatWarningsAsErrors enabled
  • this particular warning, because it's coming from deep in the Serilog stack and not from direct use of MSBuild Logging APIs, doesn't have a Code associated with it, so users can't use MSbuild's knobs to disable/hide this warning when it does appear

Please feel free to change this log.Warning to log.Info

@baronfel baronfel force-pushed the msbuild-based-logging branch from 8f4c123 to 843d8a3 Compare February 23, 2025 23:04
@baronfel
Copy link
Member Author

I've taken another pass at this, addressing the feedback (thanks folks!) and I'm much happier with how this integration looks now. There's only one actually functional gap, and I need a bit of direction on where I should go with that.

Copy link
Member

@sfoslund sfoslund left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Generally looks good to me, other than the 2 comments I added + those that others have already added

@baronfel
Copy link
Member Author

I've just rebased against main - the major conflict was that there's now SPDX3.0 configurations in the DI registration.

I've addressed all outstanding feedback I think - the last thing is to check out some hangs that @sfoslund reported to me today in the CLI tool itself.

@baronfel
Copy link
Member Author

@sfoslund the loop is coming from a circular dependency in the DI configuration. ILogger requires knowing the verbosity (from InputConfiguration) in order to initialize, but reading the InputConfiguration requires IConfigurationBuilder<T>, which requires ConfigFileParser, which requires IFileSystemUtils, all implementations of which require ILogger.

@baronfel
Copy link
Member Author

Alright, fixed the loop by using the strategy from main - the FileSystemUtils get a default logger with an expected verbosity.
Also fixed more warnings coming from component detection, but in a way that remaps all of them cleanly to MSBuild Information without impacting the tool experience.

I am now completely satisfied with this PR. whew!

@sfoslund
Copy link
Member

/azp run

{
services
.AddSingleton<IConfiguration, Configuration>()
.AddTransient(_ => FileSystemUtilsProvider.CreateInstance(CreateLogger(logLevel)))
.AddTransient(x =>
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

My understanding is that this will create a breaking change for API users, as they will now have to inject a logger similarly to how we are now doing it in Program.cs, is that right? This is okay with me as our next release will be a breaking change anyways, but tagging @DaveTryon for visibility

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oof, good call - I didn't realize that the dependency injection project was public API surface area. Let me noodle on how that could be fixed.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've pushed a commit that minimizes the API surface area changes, and adds a ton of xmldoc that instructs users on the new requirement of registering their own ILogger. That won't stop someone that just updates and then runs tests from failing, but maybe that will help mitigate somewhat.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@Forgind is there a way we can avoid making a breaking change here?

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

baronfel didn't come up with a way, and he knows this part much better than I do. I can try to look around, but I have little hope of success.

Copy link

Commenter does not have sufficient privileges for PR 933 in repo microsoft/sbom-tool

@@ -1,45 +1,76 @@
steps:
- task: UseDotNet@2
displayName: 'Use .NET Core'
displayName: Use .NET Core
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please revert changes in this file

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do you dislike these changes? Is it just because they're unrelated to the PR? They eliminated a bunch of warnings in the CI pipeline, which seems like a plus to me.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm seeing a lot of commented code and unnecessary changes (like quotes and dotnet --info) which I don't like so it's hard to tell which of these changes are actually functional. Can you revert the unnecessary changes/ commented code at a minimum and I'll consider whatever's left over?

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah; I can probably do that.

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think it's about as small a change as I can make it. I considered combining restore/build or even restore/build/test, but there isn't much harm to keeping them separate.

@@ -24,17 +24,11 @@
<PackageReference Include="Serilog.Extensions.Hosting" />
<PackageReference Include="Serilog.Sinks.Console" />
<PackageReference Include="Spectre.Console.Cli" />
<PackageReference Include="System.IO.FileSystem.AccessControl" />
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What is the reason for the changes in this file?

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When I built locally, I got an error that some package references might not be needed, and it pointed here. I deleted it, and it still built, so it seems to have been right.

@@ -10,7 +10,6 @@

<ItemGroup>
<PackageReference Include="Serilog.Sinks.Console" />
<PackageReference Include="System.IO.FileSystem.AccessControl" />
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What is the reason for the change in this file?

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same as previous

{
services
.AddSingleton<IConfiguration, Configuration>()
.AddTransient(_ => FileSystemUtilsProvider.CreateInstance(CreateLogger(logLevel)))
.AddTransient(x =>
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@Forgind is there a way we can avoid making a breaking change here?

@@ -146,80 +149,6 @@ private void InspectPackageIsWellFormed(bool isManifestPathGenerated = true)
}
}

[TestMethod]
public void SbomGenerationSucceedsForDefaultProperties()
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@Forgind can you please provide your reasoning for deleting this tests here for visibility for the whole team?

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Some of the test code multitargets to net8.0 and net472. There's a target there that only executes for net472. It builds another project that only targets net8.0—and it passed net8.0 as the targetframework with which to build that project—then copies some of its assets over and tries to use them. That isn't a supported scenario and never has been. End-to-end tests should only exist if they're testing supported scenarios. It now fails because it copies in baronfel's new thing (that uses APIs that don't exist in net472). I don't think it really needs to execute them (might be wrong on that) just pack properly, but that involves loading the assembly, which causes a missing method exception.

If we wanted to avoid deleting the tests, what I'd do is either:

  • Make the relevant project multitarget to net8.0.
    • It also depends on a lot of other projects (and packages) that target net8.0, so we'd either need to make those conditional or have them also target net472.
    • This would be reasonably robust to additional changes.
  • Choose specific files to copy or not copy to the net472 project's output directory.
    • Figuring out which files would be...tricky...and it would still be an unsupported scenario.
    • This would be very fragile. A small change could break it and lead to just as much confusion as I faced.

I'm not terribly fond of either option. The second would just be kicking the can down the road, as far as I'm concerned, and the first would likely require major (infrastructure-y) changes.

@pragnya17
Copy link
Contributor

Waiting on .NET team to get back to this PR

@Forgind
Copy link

Forgind commented Jun 27, 2025

Waiting on .NET team to get back to this PR

Last I checked (in April), this was just waiting on approval.

@Forgind
Copy link

Forgind commented Jun 27, 2025

And I just resolved the merge conflict.

@sfoslund
Copy link
Member

Last I checked (in April), this was just waiting on approval.

I don't think that's accurate, some of my previous comments have not been resolved (like reverting changes to build-test-tool-template.yaml) and I believe this PR also contains a breaking change, which would need to be addressed

@Forgind
Copy link

Forgind commented Jun 27, 2025

The breaking change part was discussed already in this thread. It sounded like you wanted to avoid the breaking change, but baronfel did try to mitigate as much as possible, so I don't think there's much more to do there unless you'd rather just close this PR.

As to the build-test-tool-template.yaml changes, I minimized those, as you can see from my last two commits. It's been a couple months, but my vague recollection is that the previous version chose the wrong version of the .NET SDK, and this PR revealed that. I'd rather not un-fix a bug.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
.NET Pull requests that update .net code
Projects
None yet
7 participants