Add flag to control trace writer logging behaviour

* Fix `uses: docker://image:tag` steps when container hook is used

* Update src/Runner.Worker/ActionManager.cs

---------

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

images/Dockerfile

@@ -2,7 +2,7 @@ FROM mcr.microsoft.com/dotnet/runtime-deps:6.0 as build
 
 ARG RUNNER_VERSION
 ARG RUNNER_ARCH="x64"
-ARG RUNNER_CONTAINER_HOOKS_VERSION=0.3.1
+ARG RUNNER_CONTAINER_HOOKS_VERSION=0.3.2
 ARG DOCKER_VERSION=20.10.23
 
 RUN apt update -y && apt install curl unzip -y

src/Runner.Common/Constants.cs

@@ -155,6 +155,7 @@ namespace GitHub.Runner.Common
             {
                 public static readonly string DiskSpaceWarning = "runner.diskspace.warning";
                 public static readonly string Node12Warning = "DistributedTask.AddWarningToNode12Action";
+                public static readonly string LogTemplateErrorsToTraceWriter = "DistributedTask.LogTemplateErrorsToTraceWriter";
                 public static readonly string UseContainerPathForTemplate = "DistributedTask.UseContainerPathForTemplate";
                 public static readonly string AllowRunnerContainerHooks = "DistributedTask.AllowRunnerContainerHooks";
             }

src/Runner.Common/JobServerQueue.cs

@@ -818,6 +818,7 @@ namespace GitHub.Runner.Common
 
             return mergedRecords;
         }
+
         private async Task UploadFile(UploadFileInfo file)
         {
             bool uploadSucceed = false;

src/Runner.Listener/Configuration/ConfigurationManager.cs

@@ -137,7 +137,7 @@ namespace GitHub.Runner.Listener.Configuration
                     GitHubAuthResult authResult = await GetTenantCredential(inputUrl, registerToken, Constants.RunnerEvent.Register);
                     runnerSettings.ServerUrl = authResult.TenantUrl;
                     runnerSettings.UseV2Flow = authResult.UseV2Flow;
-                    _term.WriteLine($"Using V2 flow: {runnerSettings.UseV2Flow}");
+                    Trace.Info($"Using V2 flow: {runnerSettings.UseV2Flow}");
                     creds = authResult.ToVssCredentials();
                     Trace.Info("cred retrieved via GitHub auth");
                 }

src/Runner.Worker/ActionManager.cs

@@ -317,15 +317,28 @@ namespace GitHub.Runner.Worker
 
             if (action.Reference.Type == Pipelines.ActionSourceType.ContainerRegistry)
             {
-                Trace.Info("Load action that reference container from registry.");
+                if (FeatureManager.IsContainerHooksEnabled(executionContext.Global.Variables))
-                CachedActionContainers.TryGetValue(action.Id, out var container);
-                ArgUtil.NotNull(container, nameof(container));
-                definition.Data.Execution = new ContainerActionExecutionData()
                 {
-                    Image = container.ContainerImage
+                    Trace.Info("Load action that will run container through container hooks.");
-                };
+                    var containerAction = action.Reference as Pipelines.ContainerRegistryReference;
+                    definition.Data.Execution = new ContainerActionExecutionData()
+                    {
+                        Image = containerAction.Image,
+                    };
+                    Trace.Info($"Using action container image: {containerAction.Image}.");
+                }
+                else
+                {
+                    Trace.Info("Load action that reference container from registry.");
+                    CachedActionContainers.TryGetValue(action.Id, out var container);
+                    ArgUtil.NotNull(container, nameof(container));
+                    definition.Data.Execution = new ContainerActionExecutionData()
+                    {
+                        Image = container.ContainerImage
+                    };
 
-                Trace.Info($"Using action container image: {container.ContainerImage}.");
+                    Trace.Info($"Using action container image: {container.ContainerImage}.");
+                }
             }
             else if (action.Reference.Type == Pipelines.ActionSourceType.Repository)
             {

src/Runner.Worker/ActionManifestManager.cs

@@ -52,7 +52,7 @@ namespace GitHub.Runner.Worker
 
         public ActionDefinitionData Load(IExecutionContext executionContext, string manifestFile)
         {
-            var templateContext = CreateTemplateContext(executionContext);
+            var templateContext = CreateTemplateContext(executionContext, null, LogTemplateErrorsToTraceWriter(executionContext));
             ActionDefinitionData actionDefinition = new();
 
             // Clean up file name real quick
@@ -303,7 +303,8 @@ namespace GitHub.Runner.Worker
 
         private TemplateContext CreateTemplateContext(
             IExecutionContext executionContext,
-            IDictionary<string, PipelineContextData> extraExpressionValues = null)
+            IDictionary<string, PipelineContextData> extraExpressionValues = null,
+            bool addErrorsToTraceWriter = true)
         {
             var result = new TemplateContext
             {
@@ -315,6 +316,7 @@ namespace GitHub.Runner.Worker
                     maxBytes: 10 * 1024 * 1024),
                 Schema = _actionManifestSchema,
                 TraceWriter = executionContext.ToTemplateTraceWriter(),
+                LogErrorsToTraceWriter = addErrorsToTraceWriter
             };
 
             // Expression values from execution context
@@ -448,7 +450,7 @@ namespace GitHub.Runner.Worker
                         };
                     }
                 }
-                else if (string.Equals(usingToken.Value, "node12", StringComparison.OrdinalIgnoreCase)||
+                else if (string.Equals(usingToken.Value, "node12", StringComparison.OrdinalIgnoreCase) ||
                          string.Equals(usingToken.Value, "node16", StringComparison.OrdinalIgnoreCase))
                 {
                     if (string.IsNullOrEmpty(mainToken?.Value))
@@ -539,6 +541,13 @@ namespace GitHub.Runner.Worker
                 }
             }
         }
+
+        private bool LogTemplateErrorsToTraceWriter(IExecutionContext executionContext)
+        {
+            if (executionContext == null || executionContext.Global == null || executionContext.Global.EnvironmentVariables == null) return true;
+            executionContext.Global.EnvironmentVariables.TryGetValue(Constants.Runner.Features.LogTemplateErrorsToTraceWriter, out var logErrorsAsDebug);
+            return StringUtil.ConvertToBoolean(logErrorsAsDebug, defaultValue: true);
+        }
     }
 }
 

src/Runner.Worker/Container/ContainerHooks/HookInput.cs

@@ -83,7 +83,7 @@ namespace GitHub.Runner.Worker.Container.ContainerHooks
         public HookContainer(ContainerInfo container)
         {
             Image = container.ContainerImage;
-            EntryPointArgs = container.ContainerEntryPointArgs?.Split(' ').Select(arg => arg.Trim()) ?? new List<string>();
+            EntryPointArgs = container.ContainerEntryPointArgs?.Split(' ').Select(arg => arg.Trim()).Where(arg => !string.IsNullOrEmpty(arg)) ?? new List<string>();
             EntryPoint = container.ContainerEntryPoint;
             WorkingDirectory = container.ContainerWorkDirectory;
             CreateOptions = container.ContainerCreateOptions;

src/Runner.Worker/ExecutionContext.cs

@@ -21,6 +21,7 @@ using Newtonsoft.Json;
 using Sdk.RSWebApi.Contracts;
 using ObjectTemplating = GitHub.DistributedTask.ObjectTemplating;
 using Pipelines = GitHub.DistributedTask.Pipelines;
+using constants = GitHub.Runner.Common.Constants;
 
 namespace GitHub.Runner.Worker
 {
@@ -1425,4 +1426,5 @@ namespace GitHub.Runner.Worker
         public static readonly string Notice = "##[notice]";
         public static readonly string Debug = "##[debug]";
     }
+
 }

src/Runner.Worker/JobRunner.cs

@@ -150,6 +150,11 @@ namespace GitHub.Runner.Worker
                 _runnerSettings = HostContext.GetService<IConfigurationStore>().GetSettings();
                 jobContext.SetRunnerContext("name", _runnerSettings.AgentName);
 
+                if (jobContext.Global.Variables.TryGetValue(WellKnownDistributedTaskVariables.RunnerEnvironment, out var runnerEnvironment))
+                {
+                    jobContext.SetRunnerContext("environment", runnerEnvironment);
+                }
+
                 string toolsDirectory = HostContext.GetDirectory(WellKnownDirectory.Tools);
                 Directory.CreateDirectory(toolsDirectory);
                 jobContext.SetRunnerContext("tool_cache", toolsDirectory);

src/Sdk/DTObjectTemplating/ObjectTemplating/TemplateContext.cs

@@ -34,6 +34,11 @@ namespace GitHub.DistributedTask.ObjectTemplating
                 m_errors = value;
             }
         }
+        /// <summary>
+        /// Because TraceWriter has access to the ExecutionContext and is logging template errors, duplicated issues are reported.
+        /// By setting LogErrorsToTraceWriter = false TemplateContext will add errors only to TemplateValidationErrors 
+        /// </summary>
+        internal bool LogErrorsToTraceWriter = true;
 
         /// <summary>
         /// Available functions within expression contexts
@@ -120,15 +125,9 @@ namespace GitHub.DistributedTask.ObjectTemplating
             }
         }
 
-        internal void Error(TemplateValidationError error)
-        {
-            Errors.Add(error);
-            TraceWriter.Error(error.Message);
-        }
-
         internal void Error(
-            TemplateToken value,
+           TemplateToken value,
-            Exception ex)
+           Exception ex)
         {
             Error(value?.FileId, value?.Line, value?.Column, ex);
         }
@@ -141,7 +140,11 @@ namespace GitHub.DistributedTask.ObjectTemplating
         {
             var prefix = GetErrorPrefix(fileId, line, column);
             Errors.Add(prefix, ex);
-            TraceWriter.Error(prefix, ex);
+
+            if (LogErrorsToTraceWriter)
+            {
+                TraceWriter.Error(prefix, ex);
+            }
         }
 
         internal void Error(
@@ -158,12 +161,13 @@ namespace GitHub.DistributedTask.ObjectTemplating
             String message)
         {
             var prefix = GetErrorPrefix(fileId, line, column);
-            if (!String.IsNullOrEmpty(prefix))
+            var fullMessage = !String.IsNullOrEmpty(prefix) ? $"{prefix} {message}" : message;
-            {
-                message = $"{prefix} {message}";
-            }
 
-            TraceWriter.Error(message);
+            Errors.Add(fullMessage);
+            if (LogErrorsToTraceWriter)
+            {
+                TraceWriter.Error(fullMessage);
+            }
         }
 
         internal INamedValueInfo[] GetExpressionNamedValues()

src/Sdk/DTWebApi/WebApi/WellKnownDistributedTaskVariables.cs

@@ -1,4 +1,4 @@
-using System;
+using System;
 
 namespace GitHub.DistributedTask.WebApi
 {
@@ -6,5 +6,6 @@ namespace GitHub.DistributedTask.WebApi
     {
         public static readonly String JobId = "system.jobId";
         public static readonly String RunnerLowDiskspaceThreshold = "system.runner.lowdiskspacethreshold";
+        public static readonly String RunnerEnvironment = "system.runnerEnvironment";
     }
 }

src/Test/L0/Sdk/DTObjectTemplating/TemplateContextL0.cs

@@ -0,0 +1,275 @@
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using GitHub.DistributedTask.ObjectTemplating.Tokens;
+using Xunit;
+
+namespace GitHub.DistributedTask.ObjectTemplating.Tests
+{
+    public sealed class TemplateContextL0
+    {
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Common")]
+        public void VerifyErrorWithTokenAndException()
+        {
+            TemplateContext context = buildContext();
+
+            List<TemplateValidationError> expectedErrors = new List<TemplateValidationError> { new TemplateValidationError("(Line: 1, Col: 1): Exception of type 'System.Exception' was thrown.") };
+
+            context.Error(new StringToken(1, 1, 1, "some-token"), new System.Exception());
+
+            List<TemplateValidationError> templateValidationErrors = toList(context.Errors.GetEnumerator());
+
+            Assert.Single(templateValidationErrors);
+            Assert.True(areEqual(expectedErrors, templateValidationErrors));
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Common")]
+        public void VerifyErrorWithNullTokenAndException()
+        {
+            TemplateContext context = buildContext();
+
+            List<TemplateValidationError> expectedErrors = new List<TemplateValidationError> { new TemplateValidationError("System.Exception: Exception of type 'System.Exception' was thrown.") };
+
+            context.Error(null, new System.Exception());
+
+            List<TemplateValidationError> templateValidationErrors = toList(context.Errors.GetEnumerator());
+
+            Assert.Single(templateValidationErrors);
+            Assert.True(areEqual(expectedErrors, templateValidationErrors));
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Common")]
+        public void VerifyErrorWithTokenAndMessage()
+        {
+            TemplateContext context = buildContext();
+
+            List<TemplateValidationError> expectedErrors = new List<TemplateValidationError> { new TemplateValidationError("(Line: 1, Col: 1): message") };
+
+            context.Error(new StringToken(1, 1, 1, "some-token"), "message");
+
+            List<TemplateValidationError> templateValidationErrors = toList(context.Errors.GetEnumerator());
+
+            Assert.Single(templateValidationErrors);
+            Assert.True(areEqual(expectedErrors, templateValidationErrors));
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Common")]
+        public void VerifyErrorWithNullTokenAndMessage()
+        {
+            TemplateContext context = buildContext();
+
+            List<TemplateValidationError> expectedErrors = new List<TemplateValidationError> { new TemplateValidationError("message") };
+
+            context.Error(null, "message");
+
+            List<TemplateValidationError> templateValidationErrors = toList(context.Errors.GetEnumerator());
+
+            Assert.Single(templateValidationErrors);
+            Assert.True(areEqual(expectedErrors, templateValidationErrors));
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Common")]
+        public void VerifyErrorWithException()
+        {
+            TemplateContext context = buildContext();
+
+            List<TemplateValidationError> expectedErrors = new List<TemplateValidationError> { new TemplateValidationError("(Line: 2, Col: 3): Fatal template exception") };
+            List<string> expectedTracewriterErrors = new List<string> { "(Line: 2, Col: 3):" };
+
+            context.Error(1, 2, 3, new Exception("Fatal template exception"));
+
+            List<TemplateValidationError> templateValidationErrors = toList(context.Errors.GetEnumerator());
+            ListTraceWriter listTraceWriter = (ListTraceWriter)context.TraceWriter;
+            List<string> tracewriterErrors = listTraceWriter.GetErrors();
+
+            Assert.Single(templateValidationErrors);
+            Assert.True(areEqual(expectedErrors, templateValidationErrors));
+            Assert.True(expectedTracewriterErrors.SequenceEqual(tracewriterErrors));
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Common")]
+        public void VerifyErrorWithExceptionAndInnerException()
+        {
+            TemplateContext context = buildContext();
+
+            List<TemplateValidationError> expectedErrors = new List<TemplateValidationError> { new TemplateValidationError("(Line: 2, Col: 3): Fatal template exception"),
+            new TemplateValidationError("(Line: 2, Col: 3): Inner Exception") };
+            List<string> expectedTracewriterErrors = new List<string> { "(Line: 2, Col: 3):" };
+
+            Exception e = new Exception("Fatal template exception", new Exception("Inner Exception"));
+
+            context.Error(1, 2, 3, e);
+
+            List<TemplateValidationError> templateValidationErrors = toList(context.Errors.GetEnumerator());
+            ListTraceWriter listTraceWriter = (ListTraceWriter)context.TraceWriter;
+            List<string> tracewriterErrors = listTraceWriter.GetErrors();
+
+            Assert.Equal(2, templateValidationErrors.Count);
+            Assert.True(areEqual(expectedErrors, templateValidationErrors));
+            Assert.True(expectedTracewriterErrors.SequenceEqual(tracewriterErrors));
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Common")]
+        public void VerifyErrorWithLineNumbersAndMessage()
+        {
+            TemplateContext context = buildContext();
+
+            List<TemplateValidationError> expectedErrors = new List<TemplateValidationError> { new TemplateValidationError("(Line: 2, Col: 3): Fatal template exception") };
+            List<string> expectedTracewriterErrors = new List<string> { "(Line: 2, Col: 3): Fatal template exception" };
+
+            context.Error(1, 2, 3, "Fatal template exception");
+
+            List<TemplateValidationError> templateValidationErrors = toList(context.Errors.GetEnumerator());
+            ListTraceWriter listTraceWriter = (ListTraceWriter)context.TraceWriter;
+            List<string> tracewriterErrors = listTraceWriter.GetErrors();
+
+            Assert.Single(templateValidationErrors);
+            Assert.True(areEqual(expectedErrors, templateValidationErrors));
+            Assert.True(expectedTracewriterErrors.SequenceEqual(tracewriterErrors));
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Common")]
+        public void VerifyErrorWithNullLineNumbersAndMessage()
+        {
+            TemplateContext context = buildContext();
+
+            List<TemplateValidationError> expectedErrors = new List<TemplateValidationError> { new TemplateValidationError("Fatal template exception") };
+            List<string> expectedTracewriterErrors = new List<string> { "Fatal template exception" };
+
+            context.Error(null, null, null, "Fatal template exception");
+
+            List<TemplateValidationError> templateValidationErrors = toList(context.Errors.GetEnumerator());
+            ListTraceWriter listTraceWriter = (ListTraceWriter)context.TraceWriter;
+            List<string> tracewriterErrors = listTraceWriter.GetErrors();
+
+            Assert.Single(templateValidationErrors);
+            Assert.True(areEqual(expectedErrors, templateValidationErrors));
+            Assert.True(expectedTracewriterErrors.SequenceEqual(tracewriterErrors));
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Common")]
+        public void VerifyErrorWithLineNumbersAndException()
+        {
+            TemplateContext context = buildContext();
+
+            List<TemplateValidationError> expectedErrors = new List<TemplateValidationError> { new TemplateValidationError("(Line: 2, Col: 3): Fatal template exception") };
+            List<string> expectedTracewriterErrors = new List<string> { "(Line: 2, Col: 3):" };
+
+            context.Error(1, 2, 3, new Exception("Fatal template exception"));
+
+            List<TemplateValidationError> templateValidationErrors = toList(context.Errors.GetEnumerator());
+            ListTraceWriter listTraceWriter = (ListTraceWriter)context.TraceWriter;
+            List<string> tracewriterErrors = listTraceWriter.GetErrors();
+
+            Assert.Single(templateValidationErrors);
+            Assert.True(areEqual(expectedErrors, templateValidationErrors));
+            Assert.True(expectedTracewriterErrors.SequenceEqual(tracewriterErrors));
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Common")]
+        public void VerifyErrorWithNullLineNumbersAndException()
+        {
+            TemplateContext context = buildContext();
+
+            List<TemplateValidationError> expectedErrors = new List<TemplateValidationError> { new TemplateValidationError("System.Exception: Fatal template exception") };
+            List<string> expectedTracewriterErrors = new List<string> { "" };
+
+            context.Error(null, null, null, new Exception("Fatal template exception"));
+
+            List<TemplateValidationError> templateValidationErrors = toList(context.Errors.GetEnumerator());
+            ListTraceWriter listTraceWriter = (ListTraceWriter)context.TraceWriter;
+            List<string> tracewriterErrors = listTraceWriter.GetErrors();
+
+            Assert.Single(templateValidationErrors);
+            Assert.True(areEqual(expectedErrors, templateValidationErrors));
+            Assert.True(expectedTracewriterErrors.SequenceEqual(tracewriterErrors));
+        }
+
+        private TemplateContext buildContext()
+        {
+            return new TemplateContext
+            {
+                // CancellationToken = CancellationToken.None,
+                Errors = new TemplateValidationErrors(10, int.MaxValue), // Don't truncate error messages otherwise we might not scrub secrets correctly
+                Memory = new TemplateMemory(
+                maxDepth: 100,
+                maxEvents: 1000000,
+                maxBytes: 10 * 1024 * 1024),
+                Schema = null,
+                TraceWriter = new ListTraceWriter(),
+            };
+        }
+
+        private List<TemplateValidationError> toList(IEnumerator<TemplateValidationError> enumerator)
+        {
+            List<TemplateValidationError> result = new();
+            while (enumerator.MoveNext())
+            {
+                TemplateValidationError err = enumerator.Current;
+                result.Add(err);
+            }
+            return result;
+        }
+
+        private bool areEqual(List<TemplateValidationError> l1, List<TemplateValidationError> l2)
+        {
+            if (l1.Count != l2.Count) return false;
+
+            var twoLists = l1.Zip(l2, (l1Error, l2Error) => new { Elem1 = l1Error, Elem2 = l2Error });
+
+            foreach (var elem in twoLists)
+            {
+                if (elem.Elem1.Message != elem.Elem2.Message) return false;
+                if (elem.Elem1.Code != elem.Elem2.Code) return false;
+            }
+            return true;
+        }
+
+        internal sealed class ListTraceWriter : ITraceWriter
+        {
+
+            private List<string> errors = new();
+            private List<string> infoMessages = new();
+            private List<string> verboseMessages = new();
+            public void Error(string format, params object[] args)
+            {
+                errors.Add(string.Format(System.Globalization.CultureInfo.CurrentCulture, $"{format}", args));
+            }
+
+            public void Info(string format, params object[] args)
+            {
+                throw new NotImplementedException();
+            }
+
+            public void Verbose(string format, params object[] args)
+            {
+                throw new NotImplementedException();
+            }
+
+            public List<string> GetErrors()
+            {
+                return errors;
+            }
+        }
+    }
+}