Merged PR 725421: Add the ability to selectively send logs to the console

The idea is that a new listener is created that selectively sends logs based on a user configurable knob to an internal Logger that the console listener listens to (in addition to the standard Events source). When the (only) event in sent to the internal logger, the console listener displays that in the console 'as is'.

Related work items: #2074267

Author: smera

Documentation/Wiki/Flags.md

@@ -132,6 +132,7 @@ This page lists flags that can be used to configure BuildXL.
 | LogStats | Logs key/value statistics to default stats file in the same folder as the main log file. Defaults to on. |
 | LogStatus | Logs build status information to a CSV file in the same folder as the main log file. Defaults to on. |
 | LogsToRetain | The number of previous logs to retain. |
+| LogToConsole | Displays the specified messages in the console. |
 | LogToKusto | Whether to send log events to Kusto. If enabled, a valid authentication mechanism should be available with enough permissions to write into the blob storage account where logs are piped to Kusto. Use /logToKustoBlobUri:https://{storage-account-name}/{container-name} /logToKustoIdentityId:{Identity guid} and /logToKustoTenantId:{Tenant guid} to specify the destination of the log messages. |
 | LowPriority | Runs the build engine and all tools at a lower priority in order to provide better responsiveness to interactive processes on the current machine. |
 | ManageMemoryMode | Specifies the mode to manage memory under pressure. Defaults to CancellationRam where {ShortProductName} attemps to cancel processes. EmptyWorkingSet mode will empty working set of processes instead of cancellation. Suspend mode will suspend processes to free memory. |

Public/Src/App/Bxl/Args.cs

@@ -342,6 +342,9 @@ public bool TryParse(string[] args, PathTable pathTable, out ICommandLineConfigu
                         OptionHandlerFactory.CreateOption(
                             "logToKustoTenantId",
                             opt => loggingConfiguration.LogToKustoTenantId = opt.Value),
+                        OptionHandlerFactory.CreateOption(
+                            "logToConsole",
+                            opt => ParseInt32ListOption(opt, loggingConfiguration.LogEventsToConsole)),
                         OptionHandlerFactory.CreateBoolOption(
                             "debuggerBreakOnExit",
                             opt => frontEndConfiguration.DebuggerBreakOnExit = opt),

Public/Src/App/Bxl/BuildXLApp.cs

@@ -57,6 +57,7 @@
 using Azure.Storage.Blobs;
 using Azure.Core.Pipeline;
 using Microsoft.WindowsAzure.Storage.RetryPolicies;
+using BuildXL.ConsoleRedirector;
 
 namespace BuildXL
 {
@@ -1593,6 +1594,11 @@ public void ConfigureLogging(LoggingContext loggingContext)
                     {
                         ConfigureKustoLogging(loggingContext);
                     }
+
+                    if (m_configuration.LogEventsToConsole.Count > 0)
+                    {
+                        ConfigureConsoleRedirection(loggingContext);
+                    }
                 }
             }
 
@@ -2006,6 +2012,18 @@ private void ConfigureKustoLogging(LoggingContext loggingContext)
                         });
             }
 
+            private void ConfigureConsoleRedirection(LoggingContext loggingContext)
+            {
+                var consoleRedirector = new ConsoleRedirectorEventListener(
+                                            Events.Log,
+                                            m_baseTime,
+                                            m_configuration.LogEventsToConsole,
+                                            loggingContext,
+                                            m_warningManager.GetState);
+
+                AddListener(consoleRedirector);
+            }
+
             /// <summary>
             /// Registers generated event sources as merged event sources
             ///

Public/Src/App/Bxl/HelpText.cs

@@ -399,6 +399,11 @@ public static void DisplayHelp(HelpLevel helpLevel)
                 "/dumpFailedPipsLogLimit:<number>",
                 Strings.HelpText_DisplayHelp_DumpFailedPipsLogLimit);
 
+            hw.WriteOption(
+                "/logToConsole:<event id list>",
+                Strings.HelpText_DisplayHelp_LogToConsole,
+                HelpLevel.Verbose);
+
             #endregion
 
             hw.WriteBanner(Strings.HelpText_DisplayHelp_ErrorsAndWarningsBanner);

Public/Src/App/Bxl/Strings.resx

@@ -1153,4 +1153,7 @@ Example: ad2d42d2ec5d2ca0c0b7ad65402d07c7ef40b91e</value>
   <data name="App_ConfigureFileLogging_BlobListenerError" xml:space="preserve">
     <value>A problem ocurred while uploading logs to Kusto: {0}</value>
   </data>
+  <data name="HelpText_DisplayHelp_LogToConsole" xml:space="preserve">
+    <value>Displays the specified messages in the console.</value>
+  </data>
 </root>

Public/Src/App/ConsoleLogger/BuildXL.ConsoleLogger.dsc

@@ -12,6 +12,7 @@ namespace ConsoleLogger {
     export const dll = BuildXLSdk.library({
         assemblyName: "BuildXL.ConsoleLogger",
         sources: globR(d`.`, "*.cs"),
+        generateLogs: true,
         embeddedResources: [{resX: f`Strings.resx`}],
         references: [
             importFrom("BuildXL.Engine").Scheduler.dll,

Public/Src/App/ConsoleLogger/ConsoleEventListener.cs

@@ -14,6 +14,7 @@
 using BuildXL.Pips;
 using BuildXL.Pips.Operations;
 using BuildXL.Utilities;
+using BuildXL.Utilities.Collections;
 using BuildXL.Utilities.Core;
 using BuildXL.Utilities.Instrumentation.Common;
 using BuildXL.Utilities.Tracing;
@@ -212,6 +213,12 @@ public ConsoleEventListener(
             m_notWorker = notWorker;
             m_optimizeForAzureDevOps = optimizeForAzureDevOps;
             m_statusMessageThrottler = new StatusMessageThrottler(baseTime);
+
+            // Only the console listener in interested in this event source. All events specified
+            // with /logToConsole will be redirected to this event source and picked up here
+            // This avoids the redirection to show anywhere else. Observe that this event source
+            // is registered in addition to the specified eventSource
+            RegisterEventSource(ConsoleLogger.ETWLogger.Log);
         }
 
         /// <summary>
@@ -365,6 +372,16 @@ protected override void OnInformational(EventWrittenEventArgs eventData)
 
                     break;
                 }
+                // This is the case of regular log events sent to the console honoring a user configurable option
+                case (int)ConsoleRedirector.Tracing.LogEventId.LogToConsole:
+                {
+                    // The message is already fully formatted, so just put it back together
+                    object[] args = eventData.Payload == null ? CollectionUtilities.EmptyArray<object>() : eventData.Payload.ToArray();
+                    string finalMessage = string.Format(CultureInfo.CurrentCulture, eventData.Message, args);
+
+                    Output(MessageLevel.Info, finalMessage);
+                    break;
+                }
 
                 default:
                 {

Public/Src/App/ConsoleLogger/ConsoleRedirectorEventListener.cs

@@ -0,0 +1,48 @@
+// Copyright (c) Microsoft Corporation.
+// Licensed under the MIT License.
+
+using System;
+using System.Collections.Generic;
+using System.Diagnostics.CodeAnalysis;
+using System.Diagnostics.ContractsLight;
+using System.Diagnostics.Tracing;
+using BuildXL.Utilities.Instrumentation.Common;
+using BuildXL.Utilities.Tracing;
+
+namespace BuildXL
+{
+    /// <summary>
+    /// Listens to an event source and selectively send events to the console
+    /// </summary>
+    public sealed class ConsoleRedirectorEventListener : FormattingEventListener
+    {
+        private readonly HashSet<int> m_eventIdsToMap;
+        private readonly LoggingContext m_loggingContext;
+
+        /// <nodoc />
+        public ConsoleRedirectorEventListener(
+            Events eventSource,
+            DateTime baseTime,
+            IEnumerable<int> eventsToRedirect,
+            LoggingContext loggingContext,
+            WarningMapper warningMapper)
+            : base(eventSource, baseTime, warningMapper: warningMapper, level: EventLevel.Verbose, captureAllDiagnosticMessages: false, timeDisplay: TimeDisplay.Seconds)
+        {
+            Contract.Requires(eventsToRedirect != null);
+            m_eventIdsToMap = new HashSet<int>(eventsToRedirect);
+            m_loggingContext = loggingContext;
+        }
+
+        /// <inheritdoc />
+        protected override void Output(EventLevel level, EventWrittenEventArgs eventData, string text, bool doNotTranslatePaths = false)
+        {
+            if (!m_eventIdsToMap.Contains(eventData.EventId))
+            {
+                return;
+            }
+
+            // If the event should be redirected, log it via this special log message
+            ConsoleRedirector.Tracing.Logger.Log.LogToConsole(m_loggingContext, text);
+        }
+    }
+}

Public/Src/App/ConsoleLogger/Tracing/Log.cs

@@ -0,0 +1,40 @@
+// Copyright (c) Microsoft Corporation.
+// Licensed under the MIT License.
+
+using BuildXL.Utilities.Instrumentation.Common;
+
+#pragma warning disable 1591
+#pragma warning disable CA1823 // Unused field
+#nullable enable
+
+namespace BuildXL.ConsoleRedirector.Tracing
+{
+    /// <summary>
+    /// Special logging to send standard log messages to the console. Not intended for bxl components to use directly.
+    /// </summary>
+    [EventKeywordsType(typeof(Keywords))]
+    [EventTasksType(typeof(Tasks))]
+    [LoggingDetails("ConsoleRedirector")]
+    public abstract partial class Logger
+    {
+        /// <summary>
+        /// Returns the logger instance
+        /// </summary>
+        public static Logger Log => m_log;
+
+
+        /// <summary>
+        /// A <see cref="ConsoleRedirectorEventListener"/> will selectively log standard log events via this method
+        /// so the ConsoleEventListener can pick them up
+        /// </summary>
+        [GeneratedEvent(
+            (ushort)LogEventId.LogToConsole,
+            EventGenerators = BuildXL.Tracing.EventGenerators.LocalOnly,
+            EventLevel = Level.Informational,
+            EventTask = (ushort)Tasks.Unclassified,
+            Message = "{text}")]
+        public abstract void LogToConsole(LoggingContext context, string text);
+    }
+}
+
+#pragma warning restore CA1823 // Unused field

Public/Src/App/ConsoleLogger/Tracing/LogEventId.cs

@@ -0,0 +1,16 @@
+// Copyright (c) Microsoft Corporation.
+// Licensed under the MIT License.
+
+namespace BuildXL.ConsoleRedirector.Tracing
+{
+    // disable warning regarding 'missing XML comments on public API'. We don't need docs for these values
+#pragma warning disable 1591
+
+    /// <summary>
+    /// Defines event IDs corresponding to events in <see cref="Logger" />
+    /// </summary>
+    public enum LogEventId
+    {
+        LogToConsole = 15006
+    }
+}

Public/Src/App/UnitTests/Bxl/ConsoleEventListenerTests.cs

@@ -2,6 +2,8 @@
 // Licensed under the MIT License.
 
 using System;
+using System.Collections.Generic;
+using System.Reflection;
 using System.Threading;
 using BuildXL;
 using BuildXL.ToolSupport;
@@ -237,5 +239,27 @@ public void TestPercentDone()
             XAssert.AreEqual("99.95%  ", ConsoleEventListener.ComputePercentDone(1000, 1000, 50, 100));
             XAssert.AreEqual("99.95%  ", ConsoleEventListener.ComputePercentDone(9999, 10000, 50, 100));
         }
+
+        [Fact]
+        public void TestEventRedirection(bool suppressWarning)
+        {
+            CancellationTokenSource cancellationTokenSource = new CancellationTokenSource();
+            CancellationToken cancellationToken = cancellationTokenSource.Token;
+            var loggingContext = BuildXLTestBase.CreateLoggingContextForTest();
+
+            using (var console = new MockConsole())
+            // Let's create and register a redirector listener to send an arbitrary message to the console
+            using (var redirectorListener = new ConsoleRedirectorEventListener(Events.Log, DateTime.UtcNow, new List<int> { (int)TestEvents.EventId.DiagnosticEvent}, loggingContext, warningMapper: null))
+            using (var listener = new ConsoleEventListener(Events.Log, console, DateTime.UtcNow, false, cancellationToken))
+            {
+                listener.RegisterEventSource(TestEvents.Log);
+                redirectorListener.RegisterEventSource(TestEvents.Log);
+
+                var message = "I'm an event that should be redirected to the console";
+                TestEvents.Log.DiagnosticEvent(message);
+
+                console.ValidateCall(MessageLevel.Info, message);
+            }
+        }
     }
 }

Public/Src/Utilities/Configuration/ILoggingConfiguration.cs

@@ -464,5 +464,10 @@ public interface ILoggingConfiguration : IWarningHandling
         /// Default value points to the Bxl-owned identity 6e0959cf-a9ba-4988-bbf1-7facd9deda51
         /// </remarks>
         public string LogToKustoIdentityId { get; }
+
+        /// <summary>
+        /// Collection of log event ids that should be sent to the console
+        /// </summary>
+        public IReadOnlyList<int> LogEventsToConsole { get; }
     }
 }

Public/Src/Utilities/Configuration/Mutable/LoggingConfiguration.cs

@@ -66,6 +66,7 @@ public LoggingConfiguration()
 
             PerfCollectorFrequencyMs = 5_000;
             LogToKusto = false;
+            LogEventsToConsole = new List<int>();
         }
 
         /// <nodoc />
@@ -170,6 +171,7 @@ public LoggingConfiguration(ILoggingConfiguration template, PathRemapper pathRem
             LogToKustoBlobUri = template.LogToKustoBlobUri;
             LogToKustoIdentityId = template.LogToKustoIdentityId;
             LogToKustoTenantId = template.LogToKustoTenantId;
+            LogEventsToConsole = new List<int>(template.LogEventsToConsole);
         }
 
         /// <inheritdoc />
@@ -433,5 +435,11 @@ public AbsolutePath LogsRootDirectory(PathTable table)
 
         /// <inheritdoc/>
         public string LogToKustoIdentityId { get; set; }
+
+        /// <nodoc/>
+        public List<int> LogEventsToConsole { get; set; }
+
+        /// <inheritdoc/>
+        IReadOnlyList<int> ILoggingConfiguration.LogEventsToConsole => LogEventsToConsole;
     }
 }