Listener stdout logging (#2291)

* Added env variable to control wether the terminal is silent

* Log to stdout if PrintLogToStdout is enabled

* Extracted console logging to stdouttracelistener

* Remove useless usings

* Rewrite TraceListener as superclass

* Only print to stdout if env is set

* Add comment for Console.Out

* Format Listener

* Revert var name in terminal

* Check env in hostcontext instead of Tracing constructor

* Remove superclass & dupe logging code

* Log hostType

* Readonly '_' prefix 'hostType'

* Fix test

* Revert Terminal change

Co-authored-by: Ferenc Hammerl <31069338+fhammerl@users.noreply.github.com>

src/Runner.Common/Constants.cs

@@ -245,6 +245,7 @@ namespace GitHub.Runner.Common
                 // Set this env var to "node12" to downgrade the node version for internal functions (e.g hashfiles). This does NOT affect the version of node actions.
                 public static readonly string ForcedInternalNodeVersion = "ACTIONS_RUNNER_FORCED_INTERNAL_NODE_VERSION";
                 public static readonly string ForcedActionsNodeVersion = "ACTIONS_RUNNER_FORCE_ACTIONS_NODE_VERSION";
+                public static readonly string PrintLogToStdout = "ACTIONS_RUNNER_PRINT_LOG_TO_STDOUT";
             }
 
             public static class System

src/Runner.Common/HostContext.cs

@@ -94,6 +94,13 @@ namespace GitHub.Runner.Common
             this.SecretMasker.AddValueEncoder(ValueEncoders.PowerShellPreAmpersandEscape);
             this.SecretMasker.AddValueEncoder(ValueEncoders.PowerShellPostAmpersandEscape);
 
+            // Create StdoutTraceListener if ENV is set
+            StdoutTraceListener stdoutTraceListener = null;
+            if (StringUtil.ConvertToBoolean(Environment.GetEnvironmentVariable(Constants.Variables.Agent.PrintLogToStdout)))
+            {
+                stdoutTraceListener = new StdoutTraceListener(hostType);
+            }
+
             // Create the trace manager.
             if (string.IsNullOrEmpty(logFile))
             {
@@ -113,11 +120,11 @@ namespace GitHub.Runner.Common
 
                 // this should give us _diag folder under runner root directory
                 string diagLogDirectory = Path.Combine(new DirectoryInfo(Path.GetDirectoryName(Assembly.GetEntryAssembly().Location)).Parent.FullName, Constants.Path.DiagDirectory);
-                _traceManager = new TraceManager(new HostTraceListener(diagLogDirectory, hostType, logPageSize, logRetentionDays), this.SecretMasker);
+                _traceManager = new TraceManager(new HostTraceListener(diagLogDirectory, hostType, logPageSize, logRetentionDays), stdoutTraceListener, this.SecretMasker);
             }
             else
             {
-                _traceManager = new TraceManager(new HostTraceListener(logFile), this.SecretMasker);
+                _traceManager = new TraceManager(new HostTraceListener(logFile), stdoutTraceListener, this.SecretMasker);
             }
 
             _trace = GetTrace(nameof(HostContext));

src/Runner.Common/StdoutTraceListener.cs

@@ -0,0 +1,90 @@
+using GitHub.Runner.Sdk;
+using System;
+using System.Diagnostics;
+using System.Globalization;
+using System.IO;
+
+namespace GitHub.Runner.Common
+{
+    public sealed class StdoutTraceListener : ConsoleTraceListener
+    {
+        private readonly string _hostType;
+
+        public StdoutTraceListener(string hostType)
+        {
+            this._hostType = hostType;
+        }
+
+        // Copied and modified slightly from .Net Core source code. Modification was required to make it compile.
+        // There must be some TraceFilter extension class that is missing in this source code.
+        public override void TraceEvent(TraceEventCache eventCache, string source, TraceEventType eventType, int id, string message)
+        {
+            if (Filter != null && !Filter.ShouldTrace(eventCache, source, eventType, id, message, null, null, null))
+            {
+                return;
+            }
+
+            WriteHeader(source, eventType, id);
+            WriteLine(message);
+            WriteFooter(eventCache);
+        }
+
+        internal bool IsEnabled(TraceOptions opts)
+        {
+            return (opts & TraceOutputOptions) != 0;
+        }
+
+        // Altered from the original .Net Core implementation.
+        private void WriteHeader(string source, TraceEventType eventType, int id)
+        {
+            string type = null;
+            switch (eventType)
+            {
+                case TraceEventType.Critical:
+                    type = "CRIT";
+                    break;
+                case TraceEventType.Error:
+                    type = "ERR ";
+                    break;
+                case TraceEventType.Warning:
+                    type = "WARN";
+                    break;
+                case TraceEventType.Information:
+                    type = "INFO";
+                    break;
+                case TraceEventType.Verbose:
+                    type = "VERB";
+                    break;
+                default:
+                    type = eventType.ToString();
+                    break;
+            }
+
+            Write(StringUtil.Format("[{0} {1:u} {2} {3}] ", _hostType.ToUpperInvariant(), DateTime.UtcNow, type, source));
+        }
+
+        // Copied and modified slightly from .Net Core source code to make it compile. The original code
+        // accesses a private indentLevel field. In this code it has been modified to use the getter/setter.
+        private void WriteFooter(TraceEventCache eventCache)
+        {
+            if (eventCache == null)
+                return;
+
+            IndentLevel++;
+            if (IsEnabled(TraceOptions.ProcessId))
+                WriteLine("ProcessId=" + eventCache.ProcessId);
+
+            if (IsEnabled(TraceOptions.ThreadId))
+                WriteLine("ThreadId=" + eventCache.ThreadId);
+
+            if (IsEnabled(TraceOptions.DateTime))
+                WriteLine("DateTime=" + eventCache.DateTime.ToString("o", CultureInfo.InvariantCulture));
+
+            if (IsEnabled(TraceOptions.Timestamp))
+                WriteLine("Timestamp=" + eventCache.Timestamp);
+
+            IndentLevel--;
+        }
+    }
+}
+

src/Runner.Common/TraceManager.cs

@@ -16,21 +16,23 @@ namespace GitHub.Runner.Common
     {
         private readonly ConcurrentDictionary<string, Tracing> _sources = new(StringComparer.OrdinalIgnoreCase);
         private readonly HostTraceListener _hostTraceListener;
+        private readonly StdoutTraceListener _stdoutTraceListener;
         private TraceSetting _traceSetting;
         private ISecretMasker _secretMasker;
 
-        public TraceManager(HostTraceListener traceListener, ISecretMasker secretMasker)
-            : this(traceListener, new TraceSetting(), secretMasker)
+        public TraceManager(HostTraceListener traceListener, StdoutTraceListener stdoutTraceListener, ISecretMasker secretMasker)
+            : this(traceListener, stdoutTraceListener, new TraceSetting(), secretMasker)
         {
         }
 
-        public TraceManager(HostTraceListener traceListener, TraceSetting traceSetting, ISecretMasker secretMasker)
+        public TraceManager(HostTraceListener traceListener, StdoutTraceListener stdoutTraceListener, TraceSetting traceSetting, ISecretMasker secretMasker)
         {
             // Validate and store params.
             ArgUtil.NotNull(traceListener, nameof(traceListener));
             ArgUtil.NotNull(traceSetting, nameof(traceSetting));
             ArgUtil.NotNull(secretMasker, nameof(secretMasker));
             _hostTraceListener = traceListener;
+            _stdoutTraceListener = stdoutTraceListener;
             _traceSetting = traceSetting;
             _secretMasker = secretMasker;
 
@@ -81,7 +83,7 @@ namespace GitHub.Runner.Common
                     Level = sourceTraceLevel.ToSourceLevels()
                 };
             }
-            return new Tracing(name, _secretMasker, sourceSwitch, _hostTraceListener);
+            return new Tracing(name, _secretMasker, sourceSwitch, _hostTraceListener, _stdoutTraceListener);
         }
     }
 }

src/Runner.Common/Tracing.cs

@@ -12,7 +12,7 @@ namespace GitHub.Runner.Common
         private ISecretMasker _secretMasker;
         private TraceSource _traceSource;
 
-        public Tracing(string name, ISecretMasker secretMasker, SourceSwitch sourceSwitch, HostTraceListener traceListener)
+        public Tracing(string name, ISecretMasker secretMasker, SourceSwitch sourceSwitch, HostTraceListener traceListener, StdoutTraceListener stdoutTraceListener = null)
         {
             ArgUtil.NotNull(secretMasker, nameof(secretMasker));
             _secretMasker = secretMasker;
@@ -27,6 +27,10 @@ namespace GitHub.Runner.Common
             }
 
             _traceSource.Listeners.Add(traceListener);
+            if (stdoutTraceListener != null)
+            {
+                _traceSource.Listeners.Add(stdoutTraceListener);
+            }
         }
 
         public void Info(string message)

src/Test/L0/TestHostContext.cs

@@ -59,7 +59,7 @@ namespace GitHub.Runner.Common.Tests
             _secretMasker = new SecretMasker();
             _secretMasker.AddValueEncoder(ValueEncoders.JsonStringEscape);
             _secretMasker.AddValueEncoder(ValueEncoders.UriDataEscape);
-            _traceManager = new TraceManager(traceListener, _secretMasker);
+            _traceManager = new TraceManager(traceListener, null, _secretMasker);
             _trace = GetTrace(nameof(TestHostContext));
 
             // inject a terminal in silent mode so all console output