diff --git a/src/Build.UnitTests/Snapshots/TerminalLogger_Tests.LogEvaluationErrorFromEngine.Linux.verified.txt b/src/Build.UnitTests/Snapshots/TerminalLogger_Tests.LogEvaluationErrorFromEngine.Linux.verified.txt new file mode 100644 index 00000000000..ee40581440f --- /dev/null +++ b/src/Build.UnitTests/Snapshots/TerminalLogger_Tests.LogEvaluationErrorFromEngine.Linux.verified.txt @@ -0,0 +1,5 @@ +]9;4;3;\MSB0001 error EvaluationError: An error occurred during evaluation. +[?25l +[?25h +Build failed with 1 error(s) in 5.0s +]9;4;0;\ \ No newline at end of file diff --git a/src/Build.UnitTests/Snapshots/TerminalLogger_Tests.LogEvaluationErrorFromEngine.OSX.verified.txt b/src/Build.UnitTests/Snapshots/TerminalLogger_Tests.LogEvaluationErrorFromEngine.OSX.verified.txt new file mode 100644 index 00000000000..dc08c181862 --- /dev/null +++ b/src/Build.UnitTests/Snapshots/TerminalLogger_Tests.LogEvaluationErrorFromEngine.OSX.verified.txt @@ -0,0 +1,4 @@ +MSB0001 error EvaluationError: An error occurred during evaluation. +[?25l +[?25h +Build failed with 1 error(s) in 5.0s diff --git a/src/Build.UnitTests/Snapshots/TerminalLogger_Tests.LogEvaluationErrorFromEngine.Windows.verified.txt b/src/Build.UnitTests/Snapshots/TerminalLogger_Tests.LogEvaluationErrorFromEngine.Windows.verified.txt new file mode 100644 index 00000000000..ee40581440f --- /dev/null +++ b/src/Build.UnitTests/Snapshots/TerminalLogger_Tests.LogEvaluationErrorFromEngine.Windows.verified.txt @@ -0,0 +1,5 @@ +]9;4;3;\MSB0001 error EvaluationError: An error occurred during evaluation. +[?25l +[?25h +Build failed with 1 error(s) in 5.0s +]9;4;0;\ \ No newline at end of file diff --git a/src/Build.UnitTests/TerminalLogger_Tests.cs b/src/Build.UnitTests/TerminalLogger_Tests.cs index 2cbd3214f59..52defb8b171 100644 --- a/src/Build.UnitTests/TerminalLogger_Tests.cs +++ b/src/Build.UnitTests/TerminalLogger_Tests.cs @@ -16,6 +16,7 @@ using VerifyTests; using VerifyXunit; using Xunit; +using Xunit.Abstractions; using static VerifyXunit.Verifier; namespace Microsoft.Build.UnitTests @@ -49,9 +50,11 @@ public class TerminalLogger_Tests : IEventSource, IDisposable private VerifySettings _settings = new(); private readonly CultureInfo _originalCulture = Thread.CurrentThread.CurrentCulture; + private readonly ITestOutputHelper _outputHelper; - public TerminalLogger_Tests() + public TerminalLogger_Tests(ITestOutputHelper outputHelper) { + _outputHelper = outputHelper; _mockTerminal = new Terminal(_outputWriter); _terminallogger = new TerminalLogger(_mockTerminal); @@ -592,6 +595,23 @@ public Task PrintBuildSummaryMinimalVerbosity_FailedWithErrors() return Verify(_outputWriter.ToString(), _settings).UniqueForOSPlatform(); } + [Fact] + public Task LogEvaluationErrorFromEngine() + { + _terminallogger.Verbosity = LoggerVerbosity.Normal; + InvokeLoggerCallbacksForSimpleProject(succeeded: false, () => + { + ErrorRaised?.Invoke(_eventSender, new BuildErrorEventArgs( + "MSB0001", "EvaluationError", "MSBUILD", 0, 0, 0, 0, + "An error occurred during evaluation.", null, null) + { + BuildEventContext = new BuildEventContext(1, -1, -1, -1) // context that belongs to no project + }); + }); + + return Verify(_outputWriter.ToString(), _settings).UniqueForOSPlatform(); + } + [Fact] public Task PrintBuildSummaryNormalVerbosity_FailedWithErrors() { @@ -782,11 +802,11 @@ public void TestTerminalLoggerTogetherWithOtherLoggers() string logFileWithoutTL = env.ExpectFile(".binlog").Path; // Execute MSBuild with binary, file and terminal loggers - RunnerUtilities.ExecMSBuild($"{projectFile.Path} /m /bl:{logFileWithTL} -flp:logfile={Path.Combine(logFolder.Path, "logFileWithTL.log")};verbosity=diagnostic -tl:on", out bool success); + RunnerUtilities.ExecMSBuild($"{projectFile.Path} /m /bl:{logFileWithTL} -flp:logfile={Path.Combine(logFolder.Path, "logFileWithTL.log")};verbosity=diagnostic -tl:on", out bool success, outputHelper: _outputHelper); success.ShouldBeTrue(); // Execute MSBuild with binary and file loggers - RunnerUtilities.ExecMSBuild($"{projectFile.Path} /m /bl:{logFileWithoutTL} -flp:logfile={Path.Combine(logFolder.Path, "logFileWithoutTL.log")};verbosity=diagnostic", out success); + RunnerUtilities.ExecMSBuild($"{projectFile.Path} /m /bl:{logFileWithoutTL} -flp:logfile={Path.Combine(logFolder.Path, "logFileWithoutTL.log")};verbosity=diagnostic", out success, outputHelper: _outputHelper); success.ShouldBeTrue(); // Read the binary log and replay into mockLogger diff --git a/src/Build/BackEnd/Components/Logging/EventSourceSink.cs b/src/Build/BackEnd/Components/Logging/EventSourceSink.cs index 11d4a8d82e9..cfa0640c7c0 100644 --- a/src/Build/BackEnd/Components/Logging/EventSourceSink.cs +++ b/src/Build/BackEnd/Components/Logging/EventSourceSink.cs @@ -3,6 +3,7 @@ // The .NET Foundation licenses this file to you under the MIT license. using System; +using System.Diagnostics; using Microsoft.Build.Experimental.BuildCheck; using Microsoft.Build.Framework; using Microsoft.Build.Framework.Telemetry; @@ -15,6 +16,7 @@ namespace Microsoft.Build.BackEnd.Logging /// /// This class raises events on behalf of the build engine to all registered loggers. /// + [DebuggerDisplay("{Name}")] internal sealed class EventSourceSink : #if FEATURE_APPDOMAIN MarshalByRefObject, diff --git a/src/Build/BackEnd/Components/Logging/LoggingService.cs b/src/Build/BackEnd/Components/Logging/LoggingService.cs index bc0e3fb601d..487c10b69b0 100644 --- a/src/Build/BackEnd/Components/Logging/LoggingService.cs +++ b/src/Build/BackEnd/Components/Logging/LoggingService.cs @@ -9,10 +9,10 @@ using System.Reflection; using System.Threading; using Microsoft.Build.BackEnd.Components.RequestBuilder; -using Microsoft.Build.Evaluation; using Microsoft.Build.Experimental.BuildCheck; using Microsoft.Build.Experimental.BuildCheck.Infrastructure; using Microsoft.Build.Framework; +using Microsoft.Build.Logging; using Microsoft.Build.Shared; using InternalLoggerException = Microsoft.Build.Exceptions.InternalLoggerException; using LoggerDescription = Microsoft.Build.Logging.LoggerDescription; @@ -1109,7 +1109,9 @@ public bool RegisterDistributedLogger(ILogger centralLogger, LoggerDescription f EventSourceSink eventSourceSink = new EventSourceSink(); // If the logger is already in the list it should not be registered again. - if (_loggers.Contains(centralLogger)) + // Note here that we are checking for direct equivalence (fast) + // and if we're dealing with a reusable logger, we need to check its original logger (slower) + if (_loggers.Contains(centralLogger) || _loggers.Any(l => l is ReusableLogger rl && rl.OriginalLogger == centralLogger)) { return false; } @@ -1778,7 +1780,7 @@ private void InitializeLogger(ILogger logger, IEventSource sourceForLogger) { ILogger UnwrapLoggerType(ILogger log) { - while (log is ProjectCollection.ReusableLogger reusableLogger) + while (log is Microsoft.Build.Logging.ReusableLogger reusableLogger) { log = reusableLogger.OriginalLogger; } @@ -1824,12 +1826,12 @@ ILogger UnwrapLoggerType(ILogger log) /// private void UpdateMinimumMessageImportance(ILogger logger) { - var innerLogger = (logger is ProjectCollection.ReusableLogger reusableLogger) ? reusableLogger.OriginalLogger : logger; + var innerLogger = (logger is ReusableLogger reusableLogger) ? reusableLogger.OriginalLogger : logger; MessageImportance? minimumImportance = innerLogger switch { - Build.Logging.ConsoleLogger consoleLogger => consoleLogger.GetMinimumMessageImportance(), - Build.Logging.ConfigurableForwardingLogger forwardingLogger => forwardingLogger.GetMinimumMessageImportance(), + ConsoleLogger consoleLogger => consoleLogger.GetMinimumMessageImportance(), + ConfigurableForwardingLogger forwardingLogger => forwardingLogger.GetMinimumMessageImportance(), // The BuildCheck connector logger consumes only high priority messages. BuildCheckForwardingLogger => MessageImportance.High, @@ -1846,11 +1848,12 @@ private void UpdateMinimumMessageImportance(ILogger logger) // The null logger has no effect on minimum verbosity. Execution.BuildManager.NullLogger => null, - // The terminal logger consumes only high priority messages. - _ => innerLogger.GetType().FullName == "Microsoft.Build.Logging.TerminalLogger.TerminalLogger" - ? MessageImportance.High - // If the logger is not on our allow list, there are no importance guarantees. Fall back to "any importance". - : MessageImportance.Low, + TerminalLogger terminalLogger => terminalLogger.GetMinimumMessageImportance(), + _ => + innerLogger.GetType().FullName == "Microsoft.Build.Logging.TerminalLogger" + ? MessageImportance.High + // If the logger is not on our allow list, there are no importance guarantees. Fall back to "any importance". + : MessageImportance.Low, }; if (minimumImportance != null) diff --git a/src/Build/Definition/ProjectCollection.cs b/src/Build/Definition/ProjectCollection.cs index 3f42d1d9cae..5cc3c9ca91d 100644 --- a/src/Build/Definition/ProjectCollection.cs +++ b/src/Build/Definition/ProjectCollection.cs @@ -1368,7 +1368,7 @@ public void RegisterForwardingLoggers(IEnumerable remote { foreach (ForwardingLoggerRecord remoteLoggerRecord in remoteLoggers) { - _loggingService.RegisterDistributedLogger(new ReusableLogger(remoteLoggerRecord.CentralLogger), remoteLoggerRecord.ForwardingLoggerDescription); + _loggingService.RegisterDistributedLogger(new Logging.ReusableLogger(remoteLoggerRecord.CentralLogger), remoteLoggerRecord.ForwardingLoggerDescription); } } } @@ -1731,7 +1731,7 @@ private void RegisterLoggerInternal(ILogger logger) { ErrorUtilities.VerifyThrowArgumentNull(logger); Debug.Assert(_locker.IsWriteLockHeld); - _loggingService.RegisterLogger(new ReusableLogger(logger)); + _loggingService.RegisterLogger(new Logging.ReusableLogger(logger)); } /// @@ -1890,601 +1890,6 @@ public ProjectAddedToProjectCollectionEventArgs(ProjectRootElement element) public ProjectRootElement ProjectRootElement { get; } } - /// - /// The ReusableLogger wraps a logger and allows it to be used for both design-time and build-time. It internally swaps - /// between the design-time and build-time event sources in response to Initialize and Shutdown events. - /// - internal class ReusableLogger : INodeLogger, IEventSource4 - { - /// - /// The logger we are wrapping. - /// - private readonly ILogger _originalLogger; - - /// - /// Returns the logger we are wrapping. - /// - internal ILogger OriginalLogger => _originalLogger; - - /// - /// The design-time event source - /// - private IEventSource _designTimeEventSource; - - /// - /// The build-time event source - /// - private IEventSource _buildTimeEventSource; - - /// - /// The Any event handler - /// - private AnyEventHandler _anyEventHandler; - - /// - /// The BuildFinished event handler - /// - private BuildFinishedEventHandler _buildFinishedEventHandler; - - /// - /// The BuildStarted event handler - /// - private BuildStartedEventHandler _buildStartedEventHandler; - - /// - /// The Custom event handler - /// - private CustomBuildEventHandler _customBuildEventHandler; - - /// - /// The Error event handler - /// - private BuildErrorEventHandler _buildErrorEventHandler; - - /// - /// The Message event handler - /// - private BuildMessageEventHandler _buildMessageEventHandler; - - /// - /// The ProjectFinished event handler - /// - private ProjectFinishedEventHandler _projectFinishedEventHandler; - - /// - /// The ProjectStarted event handler - /// - private ProjectStartedEventHandler _projectStartedEventHandler; - - /// - /// The Status event handler - /// - private BuildStatusEventHandler _buildStatusEventHandler; - - /// - /// The TargetFinished event handler - /// - private TargetFinishedEventHandler _targetFinishedEventHandler; - - /// - /// The TargetStarted event handler - /// - private TargetStartedEventHandler _targetStartedEventHandler; - - /// - /// The TaskFinished event handler - /// - private TaskFinishedEventHandler _taskFinishedEventHandler; - - /// - /// The TaskStarted event handler - /// - private TaskStartedEventHandler _taskStartedEventHandler; - - /// - /// The Warning event handler - /// - private BuildWarningEventHandler _buildWarningEventHandler; - - /// - /// The telemetry event handler. - /// - private TelemetryEventHandler _telemetryEventHandler; - - private bool _includeEvaluationMetaprojects; - - private bool _includeEvaluationProfiles; - - private bool _includeTaskInputs; - - private bool _includeEvaluationPropertiesAndItems; - - /// - /// Constructor. - /// - public ReusableLogger(ILogger originalLogger) - { - ErrorUtilities.VerifyThrowArgumentNull(originalLogger); - _originalLogger = originalLogger; - } - - #region IEventSource Members - - /// - /// The Message logging event - /// - public event BuildMessageEventHandler MessageRaised; - - /// - /// The Error logging event - /// - public event BuildErrorEventHandler ErrorRaised; - - /// - /// The Warning logging event - /// - public event BuildWarningEventHandler WarningRaised; - - /// - /// The BuildStarted logging event - /// - public event BuildStartedEventHandler BuildStarted; - - /// - /// The BuildFinished logging event - /// - public event BuildFinishedEventHandler BuildFinished; - - /// - /// The BuildCanceled logging event - /// - public event BuildCanceledEventHandler BuildCanceled; - - /// - /// The ProjectStarted logging event - /// - public event ProjectStartedEventHandler ProjectStarted; - - /// - /// The ProjectFinished logging event - /// - public event ProjectFinishedEventHandler ProjectFinished; - - /// - /// The TargetStarted logging event - /// - public event TargetStartedEventHandler TargetStarted; - - /// - /// The TargetFinished logging event - /// - public event TargetFinishedEventHandler TargetFinished; - - /// - /// The TashStarted logging event - /// - public event TaskStartedEventHandler TaskStarted; - - /// - /// The TaskFinished logging event - /// - public event TaskFinishedEventHandler TaskFinished; - - /// - /// The Custom logging event - /// - public event CustomBuildEventHandler CustomEventRaised; - - /// - /// The Status logging event - /// - public event BuildStatusEventHandler StatusEventRaised; - - /// - /// The Any logging event - /// - public event AnyEventHandler AnyEventRaised; - - /// - /// The telemetry sent event. - /// - public event TelemetryEventHandler TelemetryLogged; - - /// - /// Should evaluation events include generated metaprojects? - /// - public void IncludeEvaluationMetaprojects() - { - if (_buildTimeEventSource is IEventSource3 buildEventSource3) - { - buildEventSource3.IncludeEvaluationMetaprojects(); - } - - if (_designTimeEventSource is IEventSource3 designTimeEventSource3) - { - designTimeEventSource3.IncludeEvaluationMetaprojects(); - } - - _includeEvaluationMetaprojects = true; - } - - /// - /// Should evaluation events include profiling information? - /// - public void IncludeEvaluationProfiles() - { - if (_buildTimeEventSource is IEventSource3 buildEventSource3) - { - buildEventSource3.IncludeEvaluationProfiles(); - } - - if (_designTimeEventSource is IEventSource3 designTimeEventSource3) - { - designTimeEventSource3.IncludeEvaluationProfiles(); - } - - _includeEvaluationProfiles = true; - } - - /// - /// Should task events include task inputs? - /// - public void IncludeTaskInputs() - { - if (_buildTimeEventSource is IEventSource3 buildEventSource3) - { - buildEventSource3.IncludeTaskInputs(); - } - - if (_designTimeEventSource is IEventSource3 designTimeEventSource3) - { - designTimeEventSource3.IncludeTaskInputs(); - } - - _includeTaskInputs = true; - } - - public void IncludeEvaluationPropertiesAndItems() - { - if (_buildTimeEventSource is IEventSource4 buildEventSource4) - { - buildEventSource4.IncludeEvaluationPropertiesAndItems(); - } - - if (_designTimeEventSource is IEventSource4 designTimeEventSource4) - { - designTimeEventSource4.IncludeEvaluationPropertiesAndItems(); - } - - _includeEvaluationPropertiesAndItems = true; - } - - #endregion - - #region ILogger Members - - /// - /// The logger verbosity - /// - public LoggerVerbosity Verbosity - { - get => _originalLogger.Verbosity; - set => _originalLogger.Verbosity = value; - } - - /// - /// The logger parameters - /// - public string Parameters - { - get => _originalLogger.Parameters; - - set => _originalLogger.Parameters = value; - } - - /// - /// If we haven't yet been initialized, we register for design time events and initialize the logger we are holding. - /// If we are in design-time mode - /// - public void Initialize(IEventSource eventSource, int nodeCount) - { - if (_designTimeEventSource == null) - { - _designTimeEventSource = eventSource; - RegisterForEvents(_designTimeEventSource); - - if (_originalLogger is INodeLogger logger) - { - logger.Initialize(this, nodeCount); - } - else - { - _originalLogger.Initialize(this); - } - } - else - { - ErrorUtilities.VerifyThrow(_buildTimeEventSource == null, "Already registered for build-time."); - _buildTimeEventSource = eventSource; - UnregisterForEvents(_designTimeEventSource); - RegisterForEvents(_buildTimeEventSource); - } - } - - /// - /// If we haven't yet been initialized, we register for design time events and initialize the logger we are holding. - /// If we are in design-time mode - /// - public void Initialize(IEventSource eventSource) - { - Initialize(eventSource, 1); - } - - /// - /// If we are in build-time mode, we unregister for build-time events and re-register for design-time events. - /// If we are in design-time mode, we unregister for design-time events and shut down the logger we are holding. - /// - public void Shutdown() - { - if (_buildTimeEventSource != null) - { - UnregisterForEvents(_buildTimeEventSource); - RegisterForEvents(_designTimeEventSource); - _buildTimeEventSource = null; - } - else - { - ErrorUtilities.VerifyThrow(_designTimeEventSource != null, "Already unregistered for design-time."); - UnregisterForEvents(_designTimeEventSource); - _originalLogger.Shutdown(); - } - } - - #endregion - - /// - /// Registers for all of the events on the specified event source. - /// - private void RegisterForEvents(IEventSource eventSource) - { - // Create the handlers. - _anyEventHandler = AnyEventRaisedHandler; - _buildFinishedEventHandler = BuildFinishedHandler; - _buildStartedEventHandler = BuildStartedHandler; - _customBuildEventHandler = CustomEventRaisedHandler; - _buildErrorEventHandler = ErrorRaisedHandler; - _buildMessageEventHandler = MessageRaisedHandler; - _projectFinishedEventHandler = ProjectFinishedHandler; - _projectStartedEventHandler = ProjectStartedHandler; - _buildStatusEventHandler = StatusEventRaisedHandler; - _targetFinishedEventHandler = TargetFinishedHandler; - _targetStartedEventHandler = TargetStartedHandler; - _taskFinishedEventHandler = TaskFinishedHandler; - _taskStartedEventHandler = TaskStartedHandler; - _buildWarningEventHandler = WarningRaisedHandler; - _telemetryEventHandler = TelemetryLoggedHandler; - - // Register for the events. - eventSource.AnyEventRaised += _anyEventHandler; - eventSource.BuildFinished += _buildFinishedEventHandler; - eventSource.BuildStarted += _buildStartedEventHandler; - eventSource.CustomEventRaised += _customBuildEventHandler; - eventSource.ErrorRaised += _buildErrorEventHandler; - eventSource.MessageRaised += _buildMessageEventHandler; - eventSource.ProjectFinished += _projectFinishedEventHandler; - eventSource.ProjectStarted += _projectStartedEventHandler; - eventSource.StatusEventRaised += _buildStatusEventHandler; - eventSource.TargetFinished += _targetFinishedEventHandler; - eventSource.TargetStarted += _targetStartedEventHandler; - eventSource.TaskFinished += _taskFinishedEventHandler; - eventSource.TaskStarted += _taskStartedEventHandler; - eventSource.WarningRaised += _buildWarningEventHandler; - - if (eventSource is IEventSource2 eventSource2) - { - eventSource2.TelemetryLogged += _telemetryEventHandler; - } - - if (eventSource is IEventSource3 eventSource3) - { - if (_includeEvaluationMetaprojects) - { - eventSource3.IncludeEvaluationMetaprojects(); - } - - if (_includeEvaluationProfiles) - { - eventSource3.IncludeEvaluationProfiles(); - } - - if (_includeTaskInputs) - { - eventSource3.IncludeTaskInputs(); - } - } - - if (eventSource is IEventSource4 eventSource4) - { - if (_includeEvaluationPropertiesAndItems) - { - eventSource4.IncludeEvaluationPropertiesAndItems(); - } - } - } - - /// - /// Unregisters for all events on the specified event source. - /// - private void UnregisterForEvents(IEventSource eventSource) - { - // Unregister for the events. - eventSource.AnyEventRaised -= _anyEventHandler; - eventSource.BuildFinished -= _buildFinishedEventHandler; - eventSource.BuildStarted -= _buildStartedEventHandler; - eventSource.CustomEventRaised -= _customBuildEventHandler; - eventSource.ErrorRaised -= _buildErrorEventHandler; - eventSource.MessageRaised -= _buildMessageEventHandler; - eventSource.ProjectFinished -= _projectFinishedEventHandler; - eventSource.ProjectStarted -= _projectStartedEventHandler; - eventSource.StatusEventRaised -= _buildStatusEventHandler; - eventSource.TargetFinished -= _targetFinishedEventHandler; - eventSource.TargetStarted -= _targetStartedEventHandler; - eventSource.TaskFinished -= _taskFinishedEventHandler; - eventSource.TaskStarted -= _taskStartedEventHandler; - eventSource.WarningRaised -= _buildWarningEventHandler; - - if (eventSource is IEventSource2 eventSource2) - { - eventSource2.TelemetryLogged -= _telemetryEventHandler; - } - - // Null out the handlers. - _anyEventHandler = null; - _buildFinishedEventHandler = null; - _buildStartedEventHandler = null; - _customBuildEventHandler = null; - _buildErrorEventHandler = null; - _buildMessageEventHandler = null; - _projectFinishedEventHandler = null; - _projectStartedEventHandler = null; - _buildStatusEventHandler = null; - _targetFinishedEventHandler = null; - _targetStartedEventHandler = null; - _taskFinishedEventHandler = null; - _taskStartedEventHandler = null; - _buildWarningEventHandler = null; - _telemetryEventHandler = null; - } - - /// - /// Handler for Warning events. - /// - private void WarningRaisedHandler(object sender, BuildWarningEventArgs e) - { - WarningRaised?.Invoke(sender, e); - } - - /// - /// Handler for TaskStarted events. - /// - private void TaskStartedHandler(object sender, TaskStartedEventArgs e) - { - TaskStarted?.Invoke(sender, e); - } - - /// - /// Handler for TaskFinished events. - /// - private void TaskFinishedHandler(object sender, TaskFinishedEventArgs e) - { - TaskFinished?.Invoke(sender, e); - } - - /// - /// Handler for TargetStarted events. - /// - private void TargetStartedHandler(object sender, TargetStartedEventArgs e) - { - TargetStarted?.Invoke(sender, e); - } - - /// - /// Handler for TargetFinished events. - /// - private void TargetFinishedHandler(object sender, TargetFinishedEventArgs e) - { - TargetFinished?.Invoke(sender, e); - } - - /// - /// Handler for Status events. - /// - private void StatusEventRaisedHandler(object sender, BuildStatusEventArgs e) - { - StatusEventRaised?.Invoke(sender, e); - } - - /// - /// Handler for ProjectStarted events. - /// - private void ProjectStartedHandler(object sender, ProjectStartedEventArgs e) - { - ProjectStarted?.Invoke(sender, e); - } - - /// - /// Handler for ProjectFinished events. - /// - private void ProjectFinishedHandler(object sender, ProjectFinishedEventArgs e) - { - ProjectFinished?.Invoke(sender, e); - } - - /// - /// Handler for Message events. - /// - private void MessageRaisedHandler(object sender, BuildMessageEventArgs e) - { - MessageRaised?.Invoke(sender, e); - } - - /// - /// Handler for Error events. - /// - private void ErrorRaisedHandler(object sender, BuildErrorEventArgs e) - { - ErrorRaised?.Invoke(sender, e); - } - - /// - /// Handler for Custom events. - /// - private void CustomEventRaisedHandler(object sender, CustomBuildEventArgs e) - { - CustomEventRaised?.Invoke(sender, e); - } - - /// - /// Handler for BuildStarted events. - /// - private void BuildStartedHandler(object sender, BuildStartedEventArgs e) - { - BuildStarted?.Invoke(sender, e); - } - - /// - /// Handler for BuildFinished events. - /// - private void BuildFinishedHandler(object sender, BuildFinishedEventArgs e) - { - BuildFinished?.Invoke(sender, e); - } - - /// - /// Handler for BuildCanceled events. - /// - private void BuildCanceledHandler(object sender, BuildCanceledEventArgs e) - { - BuildCanceled?.Invoke(sender, e); - } - - /// - /// Handler for Any events. - /// - private void AnyEventRaisedHandler(object sender, BuildEventArgs e) - { - AnyEventRaised?.Invoke(sender, e); - } - - /// - /// Handler for telemetry events. - /// - private void TelemetryLoggedHandler(object sender, TelemetryEventArgs e) - { - TelemetryLogged?.Invoke(sender, e); - } - } - /// /// Holder for the projects loaded into this collection. /// diff --git a/src/Build/Logging/FileLogger.cs b/src/Build/Logging/FileLogger.cs index 537ea3c3540..a2d306a1341 100644 --- a/src/Build/Logging/FileLogger.cs +++ b/src/Build/Logging/FileLogger.cs @@ -268,6 +268,7 @@ private void ApplyFileLoggerParameter(string parameterName, string parameterValu /// private Encoding _encoding = new UTF8Encoding(false); #endif + /// /// File logger parameters delimiters. /// diff --git a/src/Build/Logging/ReusableLogger.cs b/src/Build/Logging/ReusableLogger.cs new file mode 100644 index 00000000000..c1a5a359439 --- /dev/null +++ b/src/Build/Logging/ReusableLogger.cs @@ -0,0 +1,589 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Diagnostics; +using Microsoft.Build.Framework; +using Microsoft.Build.Framework.Telemetry; +using Microsoft.Build.Shared; + +namespace Microsoft.Build.Logging; + + +/// +/// The ReusableLogger wraps a and allows it to be used for both design-time and build-time. It internally swaps +/// between the design-time and build-time event sources in response to and events. +/// Use this if you'd like to provide the same instance of an to both a +/// / _and_ +/// directly during a call to one of the -accepting overloads of . +/// +/// +/// This class needs to always implement the most-recent IEventSource interface so that it doesn't act as a limiter on the capabilities +/// of ILoggers passed to it. +/// +[DebuggerDisplay("{OriginalLogger}")] +internal class ReusableLogger : INodeLogger, IEventSource5 +{ + /// + /// The logger we are wrapping. + /// + private readonly ILogger _originalLogger; + + /// + /// Returns the logger we are wrapping. + /// + internal ILogger OriginalLogger => _originalLogger; + + /// + /// The design-time event source + /// + private IEventSource? _designTimeEventSource; + + /// + /// The build-time event source + /// + private IEventSource? _buildTimeEventSource; + + /// + /// The Any event handler + /// + private AnyEventHandler? _anyEventHandler; + + /// + /// The BuildFinished event handler + /// + private BuildFinishedEventHandler? _buildFinishedEventHandler; + + /// + /// The BuildStarted event handler + /// + private BuildStartedEventHandler? _buildStartedEventHandler; + + /// + /// The Custom event handler + /// + private CustomBuildEventHandler? _customBuildEventHandler; + + /// + /// The Error event handler + /// + private BuildErrorEventHandler? _buildErrorEventHandler; + + /// + /// The Message event handler + /// + private BuildMessageEventHandler? _buildMessageEventHandler; + + /// + /// The ProjectFinished event handler + /// + private ProjectFinishedEventHandler? _projectFinishedEventHandler; + + /// + /// The ProjectStarted event handler + /// + private ProjectStartedEventHandler? _projectStartedEventHandler; + + /// + /// The Status event handler + /// + private BuildStatusEventHandler? _buildStatusEventHandler; + + /// + /// The TargetFinished event handler + /// + private TargetFinishedEventHandler? _targetFinishedEventHandler; + + /// + /// The TargetStarted event handler + /// + private TargetStartedEventHandler? _targetStartedEventHandler; + + /// + /// The TaskFinished event handler + /// + private TaskFinishedEventHandler? _taskFinishedEventHandler; + + /// + /// The TaskStarted event handler + /// + private TaskStartedEventHandler? _taskStartedEventHandler; + + /// + /// The Warning event handler + /// + private BuildWarningEventHandler? _buildWarningEventHandler; + + /// + /// The telemetry event handler. + /// + private TelemetryEventHandler? _telemetryEventHandler; + + /// + /// The worker node telemetry logged event handler. + /// + private WorkerNodeTelemetryEventHandler? _workerNodeTelemetryLoggedHandler; + + private bool _includeEvaluationMetaprojects; + + private bool _includeEvaluationProfiles; + + private bool _includeTaskInputs; + + private bool _includeEvaluationPropertiesAndItems; + + public ReusableLogger(ILogger? originalLogger) + { + ErrorUtilities.VerifyThrowArgumentNull(originalLogger); + _originalLogger = originalLogger!; + } + + #region IEventSource Members + + /// + /// The Message logging event + /// + public event BuildMessageEventHandler? MessageRaised; + + /// + /// The Error logging event + /// + public event BuildErrorEventHandler? ErrorRaised; + + /// + /// The Warning logging event + /// + public event BuildWarningEventHandler? WarningRaised; + + /// + /// The BuildStarted logging event + /// + public event BuildStartedEventHandler? BuildStarted; + + /// + /// The BuildFinished logging event + /// + public event BuildFinishedEventHandler? BuildFinished; + + /// + /// The BuildCanceled logging event + /// + public event BuildCanceledEventHandler? BuildCanceled; + + /// + /// The ProjectStarted logging event + /// + public event ProjectStartedEventHandler? ProjectStarted; + + /// + /// The ProjectFinished logging event + /// + public event ProjectFinishedEventHandler? ProjectFinished; + + /// + /// The TargetStarted logging event + /// + public event TargetStartedEventHandler? TargetStarted; + + /// + /// The TargetFinished logging event + /// + public event TargetFinishedEventHandler? TargetFinished; + + /// + /// The TaskStarted logging event + /// + public event TaskStartedEventHandler? TaskStarted; + + /// + /// The TaskFinished logging event + /// + public event TaskFinishedEventHandler? TaskFinished; + + /// + /// The Custom logging event + /// + public event CustomBuildEventHandler? CustomEventRaised; + + /// + /// The Status logging event + /// + public event BuildStatusEventHandler? StatusEventRaised; + + /// + /// The Any logging event + /// + public event AnyEventHandler? AnyEventRaised; + + /// + /// The telemetry sent event. + /// + public event TelemetryEventHandler? TelemetryLogged; + + /// + /// The worker node telemetry logged event. + /// + public event WorkerNodeTelemetryEventHandler? WorkerNodeTelemetryLogged; + + /// + /// Should evaluation events include generated metaprojects? + /// + public void IncludeEvaluationMetaprojects() + { + if (_buildTimeEventSource is IEventSource3 buildEventSource3) + { + buildEventSource3.IncludeEvaluationMetaprojects(); + } + + if (_designTimeEventSource is IEventSource3 designTimeEventSource3) + { + designTimeEventSource3.IncludeEvaluationMetaprojects(); + } + + _includeEvaluationMetaprojects = true; + } + + /// + /// Should evaluation events include profiling information? + /// + public void IncludeEvaluationProfiles() + { + if (_buildTimeEventSource is IEventSource3 buildEventSource3) + { + buildEventSource3.IncludeEvaluationProfiles(); + } + + if (_designTimeEventSource is IEventSource3 designTimeEventSource3) + { + designTimeEventSource3.IncludeEvaluationProfiles(); + } + + _includeEvaluationProfiles = true; + } + + /// + /// Should task events include task inputs? + /// + public void IncludeTaskInputs() + { + if (_buildTimeEventSource is IEventSource3 buildEventSource3) + { + buildEventSource3.IncludeTaskInputs(); + } + + if (_designTimeEventSource is IEventSource3 designTimeEventSource3) + { + designTimeEventSource3.IncludeTaskInputs(); + } + + _includeTaskInputs = true; + } + + public void IncludeEvaluationPropertiesAndItems() + { + if (_buildTimeEventSource is IEventSource4 buildEventSource4) + { + buildEventSource4.IncludeEvaluationPropertiesAndItems(); + } + + if (_designTimeEventSource is IEventSource4 designTimeEventSource4) + { + designTimeEventSource4.IncludeEvaluationPropertiesAndItems(); + } + + _includeEvaluationPropertiesAndItems = true; + } + + #endregion + + #region ILogger Members + + /// + /// The logger verbosity + /// + public LoggerVerbosity Verbosity + { + get => _originalLogger.Verbosity; + set => _originalLogger.Verbosity = value; + } + + /// + /// The logger parameters + /// + public string? Parameters + { + get => _originalLogger.Parameters; + + set => _originalLogger.Parameters = value; + } + + /// + /// If we haven't yet been initialized, we register for design time events and initialize the logger we are holding. + /// If we are in design-time mode already, we unregister and transition over to build-time mode. + /// + public void Initialize(IEventSource eventSource, int nodeCount) + { + if (_designTimeEventSource == null) + { + _designTimeEventSource = eventSource; + RegisterForEvents(_designTimeEventSource); + + if (_originalLogger is INodeLogger logger) + { + logger.Initialize(this, nodeCount); + } + else + { + _originalLogger.Initialize(this); + } + } + else + { + ErrorUtilities.VerifyThrow(_buildTimeEventSource == null, "Already registered for build-time."); + _buildTimeEventSource = eventSource; + UnregisterForEvents(_designTimeEventSource); + RegisterForEvents(_buildTimeEventSource); + } + } + + /// + /// If we haven't yet been initialized, we register for design time events and initialize the logger we are holding. + /// If we are in design-time mode + /// + public void Initialize(IEventSource eventSource) => Initialize(eventSource, 1); + + /// + /// If we are in build-time mode, we unregister for build-time events and re-register for design-time events. + /// If we are in design-time mode, we unregister for design-time events and shut down the logger we are holding. + /// + /// + /// Invariant: one of _buildTimeEventSource or _designTimeEventSource must be non-null. + /// + public void Shutdown() + { + if (_buildTimeEventSource != null) + { + UnregisterForEvents(_buildTimeEventSource); + RegisterForEvents(_designTimeEventSource!); + _buildTimeEventSource = null; + } + else + { + ErrorUtilities.VerifyThrow(_designTimeEventSource != null, "Already unregistered for design-time."); + UnregisterForEvents(_designTimeEventSource!); + _originalLogger.Shutdown(); + } + } + + #endregion + + /// + /// Registers for all of the events on the specified event source. + /// + private void RegisterForEvents(IEventSource eventSource) + { + // Create the handlers. + _anyEventHandler = AnyEventRaisedHandler; + _buildFinishedEventHandler = BuildFinishedHandler; + _buildStartedEventHandler = BuildStartedHandler; + _customBuildEventHandler = CustomEventRaisedHandler; + _buildErrorEventHandler = ErrorRaisedHandler; + _buildMessageEventHandler = MessageRaisedHandler; + _projectFinishedEventHandler = ProjectFinishedHandler; + _projectStartedEventHandler = ProjectStartedHandler; + _buildStatusEventHandler = StatusEventRaisedHandler; + _targetFinishedEventHandler = TargetFinishedHandler; + _targetStartedEventHandler = TargetStartedHandler; + _taskFinishedEventHandler = TaskFinishedHandler; + _taskStartedEventHandler = TaskStartedHandler; + _buildWarningEventHandler = WarningRaisedHandler; + _telemetryEventHandler = TelemetryLoggedHandler; + _workerNodeTelemetryLoggedHandler = WorkerNodeTelemetryLoggedHandler; + + // Register for the events. + eventSource.AnyEventRaised += _anyEventHandler; + eventSource.BuildFinished += _buildFinishedEventHandler; + eventSource.BuildStarted += _buildStartedEventHandler; + eventSource.CustomEventRaised += _customBuildEventHandler; + eventSource.ErrorRaised += _buildErrorEventHandler; + eventSource.MessageRaised += _buildMessageEventHandler; + eventSource.ProjectFinished += _projectFinishedEventHandler; + eventSource.ProjectStarted += _projectStartedEventHandler; + eventSource.StatusEventRaised += _buildStatusEventHandler; + eventSource.TargetFinished += _targetFinishedEventHandler; + eventSource.TargetStarted += _targetStartedEventHandler; + eventSource.TaskFinished += _taskFinishedEventHandler; + eventSource.TaskStarted += _taskStartedEventHandler; + eventSource.WarningRaised += _buildWarningEventHandler; + + if (eventSource is IEventSource2 eventSource2) + { + eventSource2.TelemetryLogged += _telemetryEventHandler; + } + + if (eventSource is IEventSource3 eventSource3) + { + if (_includeEvaluationMetaprojects) + { + eventSource3.IncludeEvaluationMetaprojects(); + } + + if (_includeEvaluationProfiles) + { + eventSource3.IncludeEvaluationProfiles(); + } + + if (_includeTaskInputs) + { + eventSource3.IncludeTaskInputs(); + } + } + + if (eventSource is IEventSource4 eventSource4) + { + if (_includeEvaluationPropertiesAndItems) + { + eventSource4.IncludeEvaluationPropertiesAndItems(); + } + } + + if (eventSource is IEventSource5 eventSource5) + { + eventSource5.WorkerNodeTelemetryLogged += _workerNodeTelemetryLoggedHandler; + } + } + + /// + /// Unregisters for all events on the specified event source. + /// + private void UnregisterForEvents(IEventSource eventSource) + { + // Unregister for the events. + eventSource.AnyEventRaised -= _anyEventHandler; + eventSource.BuildFinished -= _buildFinishedEventHandler; + eventSource.BuildStarted -= _buildStartedEventHandler; + eventSource.CustomEventRaised -= _customBuildEventHandler; + eventSource.ErrorRaised -= _buildErrorEventHandler; + eventSource.MessageRaised -= _buildMessageEventHandler; + eventSource.ProjectFinished -= _projectFinishedEventHandler; + eventSource.ProjectStarted -= _projectStartedEventHandler; + eventSource.StatusEventRaised -= _buildStatusEventHandler; + eventSource.TargetFinished -= _targetFinishedEventHandler; + eventSource.TargetStarted -= _targetStartedEventHandler; + eventSource.TaskFinished -= _taskFinishedEventHandler; + eventSource.TaskStarted -= _taskStartedEventHandler; + eventSource.WarningRaised -= _buildWarningEventHandler; + + if (eventSource is IEventSource2 eventSource2) + { + eventSource2.TelemetryLogged -= _telemetryEventHandler; + } + + if (eventSource is IEventSource5 eventSource5) + { + eventSource5.WorkerNodeTelemetryLogged -= _workerNodeTelemetryLoggedHandler; + } + + // Null out the handlers. + _anyEventHandler = null; + _buildFinishedEventHandler = null; + _buildStartedEventHandler = null; + _customBuildEventHandler = null; + _buildErrorEventHandler = null; + _buildMessageEventHandler = null; + _projectFinishedEventHandler = null; + _projectStartedEventHandler = null; + _buildStatusEventHandler = null; + _targetFinishedEventHandler = null; + _targetStartedEventHandler = null; + _taskFinishedEventHandler = null; + _taskStartedEventHandler = null; + _buildWarningEventHandler = null; + _telemetryEventHandler = null; + _workerNodeTelemetryLoggedHandler = null; + } + + /// + /// Handler for Warning events. + /// + private void WarningRaisedHandler(object sender, BuildWarningEventArgs e) => WarningRaised?.Invoke(sender, e); + + /// + /// Handler for TaskStarted events. + /// + private void TaskStartedHandler(object sender, TaskStartedEventArgs e) => TaskStarted?.Invoke(sender, e); + + /// + /// Handler for TaskFinished events. + /// + private void TaskFinishedHandler(object sender, TaskFinishedEventArgs e) => TaskFinished?.Invoke(sender, e); + + /// + /// Handler for TargetStarted events. + /// + private void TargetStartedHandler(object sender, TargetStartedEventArgs e) => TargetStarted?.Invoke(sender, e); + + /// + /// Handler for TargetFinished events. + /// + private void TargetFinishedHandler(object sender, TargetFinishedEventArgs e) => TargetFinished?.Invoke(sender, e); + + /// + /// Handler for Status events. + /// + private void StatusEventRaisedHandler(object sender, BuildStatusEventArgs e) => StatusEventRaised?.Invoke(sender, e); + + /// + /// Handler for ProjectStarted events. + /// + private void ProjectStartedHandler(object sender, ProjectStartedEventArgs e) => ProjectStarted?.Invoke(sender, e); + + /// + /// Handler for ProjectFinished events. + /// + private void ProjectFinishedHandler(object sender, ProjectFinishedEventArgs e) => ProjectFinished?.Invoke(sender, e); + + /// + /// Handler for Message events. + /// + private void MessageRaisedHandler(object sender, BuildMessageEventArgs e) => MessageRaised?.Invoke(sender, e); + + /// + /// Handler for Error events. + /// + private void ErrorRaisedHandler(object sender, BuildErrorEventArgs e) => ErrorRaised?.Invoke(sender, e); + + /// + /// Handler for Custom events. + /// + private void CustomEventRaisedHandler(object sender, CustomBuildEventArgs e) => CustomEventRaised?.Invoke(sender, e); + + /// + /// Handler for BuildStarted events. + /// + private void BuildStartedHandler(object sender, BuildStartedEventArgs e) => BuildStarted?.Invoke(sender, e); + + /// + /// Handler for BuildFinished events. + /// + private void BuildFinishedHandler(object sender, BuildFinishedEventArgs e) => BuildFinished?.Invoke(sender, e); + + /// + /// Handler for BuildCanceled events. + /// + private void BuildCanceledHandler(object sender, BuildCanceledEventArgs e) => BuildCanceled?.Invoke(sender, e); + + /// + /// Handler for Any events. + /// + private void AnyEventRaisedHandler(object sender, BuildEventArgs e) => AnyEventRaised?.Invoke(sender, e); + + /// + /// Handler for telemetry events. + /// + private void TelemetryLoggedHandler(object sender, TelemetryEventArgs e) => TelemetryLogged?.Invoke(sender, e); + + /// + /// Handler for worker node telemetry logged events. + /// + private void WorkerNodeTelemetryLoggedHandler(object? sender, WorkerNodeTelemetryEventArgs e) => WorkerNodeTelemetryLogged?.Invoke(sender, e); +} diff --git a/src/Build/Logging/TerminalLogger/TerminalLogger.cs b/src/Build/Logging/TerminalLogger/TerminalLogger.cs index 8a75f025e2a..f84d5d66ffb 100644 --- a/src/Build/Logging/TerminalLogger/TerminalLogger.cs +++ b/src/Build/Logging/TerminalLogger/TerminalLogger.cs @@ -283,7 +283,7 @@ internal static ILogger CreateTerminalOrConsoleLogger(string[]? args, bool suppo { return new TerminalLogger(verbosity, originalConsoleMode); } - + // If explicitly disabled, always use console logger if (isDisabled) { @@ -354,7 +354,6 @@ public void Initialize(IEventSource eventSource) eventSource.TargetFinished += TargetFinished; eventSource.TaskStarted += TaskStarted; eventSource.StatusEventRaised += StatusEventRaised; - eventSource.MessageRaised += MessageRaised; eventSource.WarningRaised += WarningRaised; eventSource.ErrorRaised += ErrorRaised; @@ -444,7 +443,6 @@ private bool TryApplyShowCommandLineParameter(string? parameterValue) return true; } - /// public void Shutdown() { @@ -456,6 +454,16 @@ public void Shutdown() _cts.Dispose(); } + public MessageImportance GetMinimumMessageImportance() + { + if (Verbosity == LoggerVerbosity.Quiet) + { + // If the verbosity is quiet, we don't want to log anything. + return MessageImportance.High - 1; + } + return MessageImportance.High; + } + #endregion #region Logger callbacks @@ -1173,7 +1181,7 @@ private static bool IsAuthProviderMessage(string? message) => return null; } } - + /// /// The callback. /// @@ -1190,7 +1198,9 @@ private void ErrorRaised(object sender, BuildErrorEventArgs e) else { // It is necessary to display error messages reported by MSBuild, even if it's not tracked in _projects collection or the verbosity is Quiet. - RenderImmediateMessage(FormatErrorMessage(e, Indentation)); + // For nicer formatting, any messages from the engine we strip the file portion from. + bool hasMSBuildPlaceholderLocation = e.File.Equals("MSBUILD", StringComparison.Ordinal); + RenderImmediateMessage(FormatErrorMessage(e, Indentation, requireFileAndLinePortion: !hasMSBuildPlaceholderLocation)); _buildErrorsCount++; } } @@ -1405,7 +1415,7 @@ private string FormatSimpleMessageWithoutFileData(BuildMessageEventArgs e, strin prependIndentation: true); } - private string FormatErrorMessage(BuildErrorEventArgs e, string indent) + private string FormatErrorMessage(BuildErrorEventArgs e, string indent, bool requireFileAndLinePortion = true) { return FormatEventMessage( category: AnsiCodes.Colorize("error", TerminalColor.Red), @@ -1418,7 +1428,8 @@ private string FormatErrorMessage(BuildErrorEventArgs e, string indent) columnNumber: e.ColumnNumber, endColumnNumber: e.EndColumnNumber, indent, - terminalWidth: Terminal.Width); + terminalWidth: Terminal.Width, + requireFileAndLinePortion: requireFileAndLinePortion); } private static string FormatEventMessage( @@ -1438,6 +1449,7 @@ private static string FormatEventMessage( { message ??= string.Empty; StringBuilder builder = new(128); + if (prependIndentation) { builder.Append(indent); @@ -1447,7 +1459,7 @@ private static string FormatEventMessage( { if (string.IsNullOrEmpty(file)) { - builder.Append("MSBUILD : "); // Should not be localized. + builder.Append("MSBUILD : "); // Should not be localized. } else { diff --git a/src/Build/Microsoft.Build.csproj b/src/Build/Microsoft.Build.csproj index c2611f45952..3bddd583348 100644 --- a/src/Build/Microsoft.Build.csproj +++ b/src/Build/Microsoft.Build.csproj @@ -176,6 +176,7 @@ + diff --git a/src/MSBuild.UnitTests/XMake_Tests.cs b/src/MSBuild.UnitTests/XMake_Tests.cs index 836c3dab0ab..a8d752ac5dd 100644 --- a/src/MSBuild.UnitTests/XMake_Tests.cs +++ b/src/MSBuild.UnitTests/XMake_Tests.cs @@ -31,6 +31,48 @@ namespace Microsoft.Build.UnitTests { public class XMakeAppTests : IDisposable { + public static TheoryData MinimumMessageImportanceTestData + { + get + { + var data = new TheoryData + { + { "/v:diagnostic /tl:off", MessageImportance.Low }, + { "/v:detailed /tl:off", MessageImportance.Low }, + { "/v:normal /tl:off", MessageImportance.Normal }, + { "/v:minimal /tl:off", MessageImportance.High }, + { "/v:quiet /tl:off", MessageImportance.High - 1 }, + { "/v:diagnostic /bl", MessageImportance.Low }, + { "/v:detailed /bl", MessageImportance.Low }, + { "/v:normal /bl", MessageImportance.Low }, // v:normal but with binary logger so everything must be logged + { "/v:minimal /bl", MessageImportance.Low }, // v:minimal but with binary logger so everything must be logged + { "/v:quiet /bl", MessageImportance.Low }, // v:quiet but with binary logger so everything must be logged + { "/v:diagnostic /check", MessageImportance.Low }, + { "/v:detailed /check", MessageImportance.Low }, + { "/v:normal /check", MessageImportance.Normal }, + { "/v:minimal /check", MessageImportance.High }, + { "/v:quiet /check", MessageImportance.High }, + { "/v:diagnostic /tl:on", MessageImportance.High }, + { "/v:detailed /tl:on", MessageImportance.High }, + { "/v:normal /tl:on", MessageImportance.High }, + { "/v:minimal /tl:on", MessageImportance.High }, + { "/v:quiet /tl:on", MessageImportance.High - 1 } + }; + + return data; + } + } + + private static string GenerateMessageImportanceProjectFile(MessageImportance expectedMinimumMessageImportance) + { + return ObjectModelHelpers.CleanupFileContents($"\n" + + $" \n" + + $" \n" + + $" \n" + + $" \n" + + ""); + } + #if USE_MSBUILD_DLL_EXTN private const string MSBuildExeName = "MSBuild.dll"; #else @@ -43,7 +85,7 @@ public class XMakeAppTests : IDisposable public XMakeAppTests(ITestOutputHelper output) { _output = output; - _env = UnitTests.TestEnvironment.Create(_output); + _env = TestEnvironment.Create(_output); } private static string TestAssetsRootPath { get; } = Path.Combine(Path.Combine(Path.GetDirectoryName(typeof(XMakeAppTests).Assembly.Location) ?? AppContext.BaseDirectory), "TestAssets"); @@ -2498,7 +2540,7 @@ public void MissingOptionalLoggersAreIgnored(string logger, string expectedLogge [InlineData("-logger:,Logger.dll", "Logger.dll")] public void LoggerThrowsIOExceptionWhenDllNotFound(string logger, string expectedLoggerName) { - string projectString =""; + string projectString = ""; var tempDir = _env.CreateFolder(); var projectFile = tempDir.CreateFile("iologgertest.proj", projectString); @@ -2515,7 +2557,7 @@ public void LoggerThrowsIOExceptionWhenDllNotFound(string logger, string expecte [InlineData("-distributedlogger:,BadFile.dll", "BadFile.dll")] public void LoggerThrowsBadImageFormatExceptionWhenFileIsInvalid(string logger, string expectedLoggerName) { - string projectString =""; + string projectString = ""; var tempDir = _env.CreateFolder(); var projectFile = tempDir.CreateFile("badimagetest.proj", projectString); @@ -2722,7 +2764,8 @@ public override bool Execute() bool shouldLogHigh = Log.LogsMessagesOfImportance(MessageImportance.High); bool shouldLogNormal = Log.LogsMessagesOfImportance(MessageImportance.Normal); bool shouldLogLow = Log.LogsMessagesOfImportance(MessageImportance.Low); - return (MessageImportance)ExpectedMinimumMessageImportance switch + var value = (MessageImportance)ExpectedMinimumMessageImportance; + var result = value switch { MessageImportance.High - 1 => !shouldLogHigh && !shouldLogNormal && !shouldLogLow, MessageImportance.High => shouldLogHigh && !shouldLogNormal && !shouldLogLow, @@ -2730,6 +2773,21 @@ public override bool Execute() MessageImportance.Low => shouldLogHigh && shouldLogNormal && shouldLogLow, _ => false }; + if (!result) + { + var enumName = + value == MessageImportance.High - 1 + ? "Nothing" +#if NET + : Enum.GetName(value); +#else + : Enum.GetName(typeof(MessageImportance), value); +#endif + + Log.LogError($"Expected minimum message importance {enumName} did not match actual logging behavior:\n" + + $"\tShouldLogHigh={shouldLogHigh}, ShouldLogNormal={shouldLogNormal}, ShouldLogLow={shouldLogLow}"); + } + return result; } } @@ -2740,7 +2798,7 @@ public override bool Execute() [InlineData("/getProperty:p", false)] public void EndToEndVersionMessage(string arguments, bool shouldContainVersionMessage) { - using TestEnvironment testEnvironment = UnitTests.TestEnvironment.Create(); + using TestEnvironment testEnvironment = TestEnvironment.Create(); string projectContents = ObjectModelHelpers.CleanupFileContents(""" @@ -2769,48 +2827,17 @@ public void EndToEndVersionMessage(string arguments, bool shouldContainVersionMe } [Theory] - [InlineData("/v:diagnostic", MessageImportance.Low)] - [InlineData("/v:detailed", MessageImportance.Low)] - [InlineData("/v:normal", MessageImportance.Normal)] - [InlineData("/v:minimal", MessageImportance.High)] - [InlineData("/v:quiet", MessageImportance.High - 1)] - - [InlineData("/v:diagnostic /bl", MessageImportance.Low)] - [InlineData("/v:detailed /bl", MessageImportance.Low)] - [InlineData("/v:normal /bl", MessageImportance.Low)] // v:normal but with binary logger so everything must be logged - [InlineData("/v:minimal /bl", MessageImportance.Low)] // v:minimal but with binary logger so everything must be logged - [InlineData("/v:quiet /bl", MessageImportance.Low)] // v:quiet but with binary logger so everything must be logged - - [InlineData("/v:diagnostic /check", MessageImportance.Low)] - [InlineData("/v:detailed /check", MessageImportance.Low)] - [InlineData("/v:normal /check", MessageImportance.Normal)] - [InlineData("/v:minimal /check", MessageImportance.High)] - [InlineData("/v:quiet /check", MessageImportance.High)] - - [InlineData("/v:diagnostic /tl", MessageImportance.Low)] - [InlineData("/v:detailed /tl", MessageImportance.Low)] - [InlineData("/v:normal /tl", MessageImportance.Normal)] - [InlineData("/v:minimal /tl", MessageImportance.High)] - [InlineData("/v:quiet /tl", MessageImportance.High - 1)] - public void EndToEndMinimumMessageImportance(string arguments, MessageImportance expectedMinimumMessageImportance) - { - using TestEnvironment testEnvironment = UnitTests.TestEnvironment.Create(); - - string projectContents = ObjectModelHelpers.CleanupFileContents(@" - - - - - - + [MemberData(nameof(MinimumMessageImportanceTestData))] + public void EndToEndMinimumMessageImportance_InProc(string arguments, MessageImportance expectedMinimumMessageImportance) + { + using TestEnvironment testEnvironment = TestEnvironment.Create(); -"); + string projectContents = GenerateMessageImportanceProjectFile(expectedMinimumMessageImportance); TransientTestProjectWithFiles testProject = testEnvironment.CreateTestProjectWithFiles(projectContents); // If /bl is specified, set a path for the binlog that is defined by the test environment - string pattern = @"/v:(\w+)\s/b"; ; - Regex.Match(arguments, pattern); + string pattern = @"/v:(\w+)\s/b"; Match match = Regex.Match(arguments, pattern); if (match.Success) { @@ -2818,14 +2845,37 @@ public void EndToEndMinimumMessageImportance(string arguments, MessageImportance arguments = arguments.Replace("/bl", $"/bl:{binlogPath}"); } - // Build in-proc. + // Build in-proc only. RunnerUtilities.ExecMSBuild($"{arguments} \"{testProject.ProjectFile}\"", out bool success, _output); success.ShouldBeTrue(); + } - // Build out-of-proc to exercise both logging code paths. + [Theory] + [MemberData(nameof(MinimumMessageImportanceTestData))] + public void EndToEndMinimumMessageImportance_OutOfProc(string arguments, MessageImportance expectedMinimumMessageImportance) + { + using var testEnvironment = TestEnvironment.Create(); + + // NOTE for this test: out of proc nodes _always_ log every message, so we rewrite the expected minimum message importance to accept every message. + expectedMinimumMessageImportance = MessageImportance.Low; + + string projectContents = GenerateMessageImportanceProjectFile(expectedMinimumMessageImportance); + + TransientTestProjectWithFiles testProject = testEnvironment.CreateTestProjectWithFiles(projectContents); + + // If /bl is specified, set a path for the binlog that is defined by the test environment + string pattern = @"/v:(\w+)\s/b"; + Match match = Regex.Match(arguments, pattern); + if (match.Success) + { + string binlogPath = Path.Combine(testProject.TestRoot, match.Groups[1] + ".binlog"); + arguments = arguments.Replace("/bl", $"/bl:{binlogPath}"); + } + + // Build out-of-proc only. testEnvironment.SetEnvironmentVariable("MSBUILDNOINPROCNODE", "1"); testEnvironment.SetEnvironmentVariable("MSBUILDDISABLENODEREUSE", "1"); - RunnerUtilities.ExecMSBuild($"{arguments} \"{testProject.ProjectFile}\"", out success, _output); + RunnerUtilities.ExecMSBuild($"{arguments} \"{testProject.ProjectFile}\"", out bool success, _output); success.ShouldBeTrue(); } diff --git a/src/MSBuild/XMake.cs b/src/MSBuild/XMake.cs index b633d8c810b..b1e2f485a27 100644 --- a/src/MSBuild/XMake.cs +++ b/src/MSBuild/XMake.cs @@ -1382,9 +1382,18 @@ internal static bool BuildProject( bool isPreprocess = preprocessWriter != null; bool isTargets = targetsWriter != null; + ILogger[] evaluationLoggers = + [ + // all of the loggers that are single-node only + .. loggers, + // all of the central loggers for multi-node systems. These need to be resilient to multiple calls + // to Initialize + .. distributedLoggerRecords.Select(d => d.CentralLogger) + ]; + projectCollection = new ProjectCollection( globalProperties, - loggers, + evaluationLoggers, null, toolsetDefinitionLocations, cpuCount,