Skip to content
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

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

Open
wants to merge 14 commits into
base: main
Choose a base branch
from
Open
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Prev Previous commit
Next Next commit
respond to review feedback
  • Loading branch information
baronfel committed Mar 1, 2025
commit 7348891b5572e18ed80ad729729c39b91a881ff4
Original file line number Diff line number Diff line change
@@ -114,7 +114,8 @@ async Task Scan(string path)
var cmdLineParams = configuration.ToComponentDetectorCommandLineParams(cliArgumentBuilder);

var scanSettings = cliArgumentBuilder.BuildScanSettingsFromParsedArgs(cmdLineParams);

// TODO: the MSBuild pathway needs a way to disable this setting, because the CG tools write directly to stdout (which is not kind).
scanSettings.NoSummary = true;
var scanResult = await componentDetector.ScanAsync(scanSettings);

if (scanResult.ResultCode != ProcessingResultCode.Success)
47 changes: 0 additions & 47 deletions src/Microsoft.Sbom.Extensions.DependencyInjection/MSBuildLogger.cs

This file was deleted.

Original file line number Diff line number Diff line change
@@ -18,7 +18,6 @@

<ItemGroup>
<PackageReference Include="AutoMapper.Extensions.Microsoft.DependencyInjection" />
<PackageReference Include="Microsoft.Build.Utilities.Core" />
<PackageReference Include="Microsoft.Extensions.Hosting" />
<PackageReference Include="Microsoft.Extensions.Http" />
<PackageReference Include="Scrutor" />
Original file line number Diff line number Diff line change
@@ -2,7 +2,6 @@
// Licensed under the MIT license. See LICENSE file in the project root for full license information.

using System.Collections.Concurrent;
using Microsoft.Build.Utilities;
using Microsoft.ComponentDetection.Orchestrator;
using Microsoft.ComponentDetection.Orchestrator.Extensions;
using Microsoft.Extensions.DependencyInjection;
@@ -56,20 +55,29 @@ public static IServiceCollection AddSbomConfiguration(this IServiceCollection se
inputConfiguration.ToConfiguration();
return inputConfiguration;
})
.AddSbomTool(logLevel);
.AddSbomTool();
return services;
}

public static IServiceCollection AddSbomTool(this IServiceCollection services, LogEventLevel logLevel = LogEventLevel.Information, TaskLoggingHelper? taskLoggingHelper = null)
public static IServiceCollection AddSbomTool(this IServiceCollection services, ILogger? logger = null)
{
services
.AddSingleton<IConfiguration, Configuration>()
.AddTransient(_ => FileSystemUtilsProvider.CreateInstance(CreateLogger(logLevel, taskLoggingHelper)))
.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.

.AddSingleton(x =>
{
logLevel = x.GetService<InputConfiguration>()?.Verbosity?.Value ?? logLevel;
return Log.Logger = CreateLogger(logLevel, taskLoggingHelper);
if (logger != null)
{
return logger;
}
else
{
var level = x.GetService<InputConfiguration>()?.Verbosity?.Value ?? LogEventLevel.Information;
var defaultLogger = CreateDefaultLogger(level);
Log.Logger = defaultLogger;
return defaultLogger;
}
})
.AddTransient(x => FileSystemUtilsProvider.CreateInstance(x.GetRequiredService<ILogger>()))
.AddTransient<IWorkflow<SbomParserBasedValidationWorkflow>, SbomParserBasedValidationWorkflow>()
.AddTransient<IWorkflow<SbomGenerationWorkflow>, SbomGenerationWorkflow>()
.AddTransient<IWorkflow<SbomRedactionWorkflow>, SbomRedactionWorkflow>()
@@ -126,7 +134,8 @@ public static IServiceCollection AddSbomTool(this IServiceCollection services, L
.AddSingleton<IFileTypeUtils, FileTypeUtils>()
.AddSingleton<ISignValidationProvider, SignValidationProvider>()
.AddSingleton<IManifestParserProvider, ManifestParserProvider>()
.AddSingleton(x => {
.AddSingleton(x =>
{
var comparer = x.GetRequiredService<IOSUtils>().GetFileSystemStringComparer();
return new FileHashesDictionary(new ConcurrentDictionary<string, FileHashes>(comparer));
})
@@ -201,33 +210,26 @@ public static IServiceCollection ConfigureLoggingProviders(this IServiceCollecti
return services;
}

private static ILogger CreateLogger(LogEventLevel logLevel, TaskLoggingHelper? taskLoggingHelper = null)
private static ILogger CreateDefaultLogger(LogEventLevel logLevel = LogEventLevel.Information)
{
if (taskLoggingHelper == null)
{
return new RemapComponentDetectionErrorsToWarningsLogger(
new LoggerConfiguration()
.MinimumLevel.ControlledBy(new LoggingLevelSwitch { MinimumLevel = logLevel })
.Filter.ByExcluding(Matching.FromSource("System.Net.Http.HttpClient"))
.Enrich.With<LoggingEnricher>()
.Enrich.FromLogContext()
.WriteTo.Map(
LoggingEnricher.LogFilePathPropertyName,
(logFilePath, wt) => wt.Async(x => x.File($"{logFilePath}")),
1) // sinkMapCountLimit
.WriteTo.Map<bool>(
LoggingEnricher.PrintStderrPropertyName,
(printLogsToStderr, wt) => wt.Logger(lc => lc
.WriteTo.Console(outputTemplate: Constants.LoggerTemplate, standardErrorFromLevel: printLogsToStderr ? LogEventLevel.Debug : null)
return new RemapComponentDetectionErrorsToWarningsLogger(
new LoggerConfiguration()
.MinimumLevel.ControlledBy(new LoggingLevelSwitch { MinimumLevel = logLevel })
.Filter.ByExcluding(Matching.FromSource("System.Net.Http.HttpClient"))
.Enrich.With<LoggingEnricher>()
.Enrich.FromLogContext()
.WriteTo.Map(
LoggingEnricher.LogFilePathPropertyName,
(logFilePath, wt) => wt.Async(x => x.File($"{logFilePath}")),
1) // sinkMapCountLimit
.WriteTo.Map<bool>(
LoggingEnricher.PrintStderrPropertyName,
(printLogsToStderr, wt) => wt.Logger(lc => lc
.WriteTo.Console(outputTemplate: Constants.LoggerTemplate, standardErrorFromLevel: printLogsToStderr ? LogEventLevel.Debug : null)

// Don't write the detection times table from DetectorProcessingService to the console, only the log file
.Filter.ByExcluding(Matching.WithProperty<string>("DetectionTimeLine", x => !string.IsNullOrEmpty(x)))),
1) // sinkMapCountLimit
.CreateLogger());
}
else
{
return new MSBuildLogger(taskLoggingHelper);
}
// Don't write the detection times table from DetectorProcessingService to the console, only the log file
.Filter.ByExcluding(Matching.WithProperty<string>("DetectionTimeLine", x => !string.IsNullOrEmpty(x)))),
1) // sinkMapCountLimit
.CreateLogger());
}
}
44 changes: 25 additions & 19 deletions src/Microsoft.Sbom.Targets/GenerateSbomTask.cs
Original file line number Diff line number Diff line change
@@ -5,7 +5,8 @@ namespace Microsoft.Sbom.Targets;

using System;
using System.Collections.Generic;
using System.Diagnostics.Tracing;
using System.Threading;
using Microsoft.Build.Framework;
using Microsoft.Build.Utilities;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
@@ -15,20 +16,24 @@ namespace Microsoft.Sbom.Targets;
using Microsoft.Sbom.Api.Providers.ExternalDocumentReferenceProviders;
using Microsoft.Sbom.Api.Providers.FilesProviders;
using Microsoft.Sbom.Api.Providers.PackagesProviders;
using Microsoft.Sbom.Common.Config;
using Microsoft.Sbom.Contracts;
using Microsoft.Sbom.Contracts.Entities;
using Microsoft.Sbom.Contracts.Interfaces;
using Microsoft.Sbom.Extensions;
using Microsoft.Sbom.Extensions.DependencyInjection;
using Serilog.Events;
using SPDX22 = Microsoft.Sbom.Parsers.Spdx22SbomParser;
using SPDX30 = Microsoft.Sbom.Parsers.Spdx30SbomParser;

/// <summary>
/// MSBuild task for generating SBOMs from build output.
/// </summary>
public partial class GenerateSbom : Task
public partial class GenerateSbom : Task, ICancelableTask
{
private CancellationTokenSource cancellationTokenSource = new CancellationTokenSource();

public void Cancel() => cancellationTokenSource.Cancel();

/// <inheritdoc/>
public override bool Execute()
{
@@ -43,12 +48,13 @@ public override bool Execute()
}

var logVerbosity = ValidateAndAssignVerbosity();
var serilogLogVerbosity = MapSerilogLevel(logVerbosity);

var msbuildLogger = new MSBuildLogger(taskLoggingHelper);
Serilog.Log.Logger = msbuildLogger;
var taskHost = Host.CreateDefaultBuilder()
.ConfigureServices((host, services) =>
services
.AddSbomTool(serilogLogVerbosity, taskLoggingHelper)
.AddSingleton<IConfiguration, Configuration>()
.AddSbomTool(msbuildLogger)
/* Manually adding some dependencies since `AddSbomTool()` does not add them when
* running the MSBuild Task from another project.
*/
@@ -98,29 +104,29 @@ public override bool Execute()
componentPath: this.BuildComponentPath,
runtimeConfiguration: runtimeConfiguration,
specifications: ValidateAndAssignSpecifications(),
externalDocumentReferenceListFile: this.ExternalDocumentListFile)).GetAwaiter().GetResult();
externalDocumentReferenceListFile: this.ExternalDocumentListFile),
this.cancellationTokenSource.Token).GetAwaiter().GetResult();
#pragma warning restore VSTHRD002 // Avoid problematic synchronous waits

if (!result.IsSuccessful)
{
Log.LogError("SBOM generation failed. Check the build log for details.");
}

foreach (var error in result.Errors)
{
Log.LogMessage(MessageImportance.Normal, "{0}({1}) - {2} - {3}", error.Entity.Id, error.Entity.EntityType, error.ErrorType, error.Details);
}

return result.IsSuccessful;
}
catch (Exception e)
{
Log.LogError($"SBOM generation failed: {e.Message}");
return false;
return Log.HasLoggedErrors;
}
}

private LogEventLevel MapSerilogLevel(EventLevel logVerbosity) =>
logVerbosity switch
{
EventLevel.Critical => LogEventLevel.Fatal,
EventLevel.Error => LogEventLevel.Error,
EventLevel.Warning => LogEventLevel.Warning,
EventLevel.Informational => LogEventLevel.Information,
EventLevel.Verbose => LogEventLevel.Verbose,
_ => LogEventLevel.Information,
};

/// <summary>
/// Check for ManifestInfo and create an SbomSpecification accordingly.
/// </summary>
59 changes: 59 additions & 0 deletions src/Microsoft.Sbom.Targets/MSBuildLogger.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,59 @@
// Copyright (c) Microsoft. All rights reserved.
// Licensed under the MIT license. See LICENSE file in the project root for full license information.

namespace Microsoft.Sbom.Targets;

using System;
using Microsoft.Build.Framework;
using Microsoft.Build.Utilities;
using Serilog.Events;
using ILogger = Serilog.ILogger;

/// <summary>
/// A class to remap Errors logged from ComponentDetection assemblies to Warnings or Errors in MSBuild from Serilog to MSBuild's native logging facilities. This class interprets a few kinds of properties from the
/// logged Serilog message:
/// <list type="bullet">
/// <item><description><c>msbuild.code</c> becomes the <c>code</c> for the <see cref="TaskLoggingHelper.LogWarning(string, string, string, string, string, int, int, int, int, string, object[])" /> or <see cref="TaskLoggingHelper.LogError(string, string, string, string, string, int, int, int, int, string, object[])"/> methods for Serilog <see cref="LogEventLevel.Warning"/>, <see cref="LogEventLevel.Error"/>, and <see cref="LogEventLevel.Fatal"/> events.</description></item>
/// <item><description><c>msbuild.importance</c> becomes the <c>importance</c> for the <see cref="TaskLoggingHelper.LogMessage(MessageImportance, string, object[])" /> method for Serilog <see cref="LogEventLevel.Debug"/> and <see cref="LogEventLevel.Information"/> events.</description></item>
/// </list>
/// </summary>
public class MSBuildLogger : ILogger
{
private readonly TaskLoggingHelper loggingHelper;

public MSBuildLogger(TaskLoggingHelper loggingHelperToWrap)
{
loggingHelper = loggingHelperToWrap;
}

public void Write(LogEvent logEvent)
{
var logLevel = logEvent.Level;
switch (logLevel)
{
case LogEventLevel.Debug:
logEvent.Properties.TryGetValue("msbuild.importance", out var debugImportance);
loggingHelper.LogMessage(TryParseImportance(debugImportance) ?? MessageImportance.Low, logEvent.RenderMessage());
break;
case LogEventLevel.Information:
logEvent.Properties.TryGetValue("msbuild.importance", out var infoImportance);
loggingHelper.LogMessage(TryParseImportance(infoImportance) ?? MessageImportance.Normal, logEvent.RenderMessage());
break;
// warnings and errors can have codes, etc - if the message has a code then use it
case LogEventLevel.Warning:
logEvent.Properties.TryGetValue("msbuild.code", out var warningCode);
loggingHelper.LogWarning(subcategory: null, warningCode: warningCode?.ToString(), helpKeyword: null, helpLink: null, file: null, lineNumber: 0, columnNumber: 0, endLineNumber: 0, endColumnNumber: 0, message: logEvent.RenderMessage());
break;
case LogEventLevel.Error:
case LogEventLevel.Fatal:
logEvent.Properties.TryGetValue("msbuild.code", out var errorCode);
loggingHelper.LogError(subcategory: null, errorCode: errorCode?.ToString(), helpKeyword: null, helpLink: null, file: null, lineNumber: 0, columnNumber: 0, endLineNumber: 0, endColumnNumber: 0, message: logEvent.RenderMessage());
break;
default:
break;
}
}

private MessageImportance? TryParseImportance(LogEventPropertyValue? infoImportance) =>
infoImportance != null && Enum.TryParse<MessageImportance>(infoImportance.ToString(), out var msbuildImportance) ? msbuildImportance : null;
}
4 changes: 2 additions & 2 deletions src/Microsoft.Sbom.Targets/Microsoft.Sbom.Targets.csproj
Original file line number Diff line number Diff line change
@@ -13,7 +13,6 @@
<CopyLocalLockFileAssemblies>true</CopyLocalLockFileAssemblies>
<SbomCLIToolTargetFramework>net8.0</SbomCLIToolTargetFramework>
<DevelopmentDependency>true</DevelopmentDependency>

<!-- This target will run when MSBuild is collecting the files to be packaged, and we'll implement it below. This property controls the dependency list for this packaging process, so by adding our custom property we hook ourselves into the process in a supported way. -->
<TargetsForTfmSpecificBuildOutput>
$(TargetsForTfmSpecificBuildOutput);CopyProjectReferencesToPackage
@@ -54,7 +53,7 @@
<Visible>true</Visible>
</Content>
</ItemGroup>
</Target>
</Target>

<ItemGroup>
<!-- these lines pack the build props/targets files to the `build` folder in the generated package.
@@ -78,6 +77,7 @@

<ItemGroup Condition="'$(TargetFramework)' == 'net472'">
<Compile Remove="GenerateSbomTask.cs" />
<Compile Remove="MSBuildLogger.cs" />
</ItemGroup>

<ItemGroup Condition="'$(TargetFramework)' != 'net472'">
1 change: 0 additions & 1 deletion src/Microsoft.Sbom.Tool/Microsoft.Sbom.Tool.csproj
Original file line number Diff line number Diff line change
@@ -24,6 +24,5 @@
<ItemGroup>
<PackageReference Include="AutoMapper.Extensions.Microsoft.DependencyInjection" />
<PackageReference Include="Microsoft.Extensions.Hosting" />
<PackageReference Include="Microsoft.Build.Utilities.Core" />
</ItemGroup>
</Project>