fix composite annotations not appearing as expected

* docker: escape key-value pair as -e KEY and VALUE being environment var

* removed code duplication, removed unused method and test

* add release notes

Co-authored-by: Nikola Jokic <nikola-jokic@github.com>

Co-authored-by: Thomas Boop <52323235+thboop@users.noreply.github.com>
Co-authored-by: Nikola Jokic <nikola-jokic@github.com>

docs/adrs/1891-container-hooks.md

@@ -16,7 +16,7 @@ We should give them that option, and publish examples how how they can create th
   - For example, the current runner overrides `HOME`, we can do that in the hook, but we shouldn't pass that hook as an ENV with the other env's the user has set, as that is not user input, it is how the runner invokes containers
 
 ## Interface
-- You will set the variable `ACTIONS_RUNNER_CONTAINER_HOOK=/Users/foo/runner/hooks.js` which is the entrypoint to your hook handler.
+- You will set the variable `ACTIONS_RUNNER_CONTAINER_HOOKS=/Users/foo/runner/hooks.js` which is the entrypoint to your hook handler.
   - There is no partial opt in, you must handle every hook 
 - We will pass a command and some args via `stdin`
 - An exit code of 0 is a success, every other exit code is a failure

releaseNote.md

@@ -1,11 +1,6 @@
-## Features
-- GHES: Support connecting to GitHub Enterprise Server Actions Service on a subdomain 
 ## Bugs
-- Fixed a bug where GITHUB_ENV would not update correctly between composite action steps (#1794)
-- Fixed runner update bug caused by `update.sh|cmd` running too long (#2044) 
+- Fixed an issue where job and service container envs were corrupted (#2091)
 ## Misc
-- Bump Newtonsoft.Json from 11.0.2 to 13.0.1 (#2012)
-- Change a periodic token expiry log message level from `WARNING` to `VERBOSE` (#2021)
 
 ## Windows x64
 We recommend configuring the runner in a root folder of the Windows drive (e.g. "C:\actions-runner"). This will help avoid issues related to service identity folder permissions and long file path restrictions on Windows.
@@ -32,7 +27,7 @@ curl -O -L https://github.com/actions/runner/releases/download/v<RUNNER_VERSION>
 tar xzf ./actions-runner-osx-x64-<RUNNER_VERSION>.tar.gz
 ```
 
-## [Pre-release] OSX arm64 (Apple silicon)
+## OSX arm64 (Apple silicon)
 
 ``` bash
 # Create a folder

src/Runner.Worker/ActionCommandManager.cs

@@ -585,6 +585,8 @@ namespace GitHub.Runner.Worker
 
         public void ProcessCommand(IExecutionContext context, string inputLine, ActionCommand command, ContainerInfo container)
         {
+            ValidateLinesAndColumns(command, context);
+        
             command.Properties.TryGetValue(IssueCommandProperties.File, out string file);
             command.Properties.TryGetValue(IssueCommandProperties.Line, out string line);
             command.Properties.TryGetValue(IssueCommandProperties.Column, out string column);

src/Runner.Worker/ActionManifestManager.cs

@@ -503,7 +503,7 @@ namespace GitHub.Runner.Worker
                 };
             }
 
-            throw new NotSupportedException(nameof(ConvertRuns));
+            throw new NotSupportedException("Missing 'using' value. 'using' requires 'composite', 'docker', 'node12' or 'node16'.");
         }
 
         private void ConvertInputs(

src/Runner.Worker/Container/DockerCommandManager.cs

@@ -107,6 +107,7 @@ namespace GitHub.Runner.Worker.Container
         public async Task<string> DockerCreate(IExecutionContext context, ContainerInfo container)
         {
             IList<string> dockerOptions = new List<string>();
+            IDictionary<string, string> environment = new Dictionary<string, string>();
             // OPTIONS
             dockerOptions.Add($"--name {container.ContainerDisplayName}");
             dockerOptions.Add($"--label {DockerInstanceLabel}");
@@ -131,11 +132,12 @@ namespace GitHub.Runner.Worker.Container
             {
                 if (String.IsNullOrEmpty(env.Value))
                 {
-                    dockerOptions.Add($"-e \"{env.Key}\"");
+                    dockerOptions.Add(DockerUtil.CreateEscapedOption("-e", env.Key));
                 }
                 else
                 {
-                    dockerOptions.Add($"-e \"{env.Key}={env.Value.Replace("\"", "\\\"")}\"");
+                    environment.Add(env.Key, env.Value);
+                    dockerOptions.Add(DockerUtil.CreateEscapedOption("-e", env.Key));
                 }
             }
 
@@ -183,7 +185,7 @@ namespace GitHub.Runner.Worker.Container
             dockerOptions.Add($"{container.ContainerEntryPointArgs}");
 
             var optionsString = string.Join(" ", dockerOptions);
-            List<string> outputStrings = await ExecuteDockerCommandAsync(context, "create", optionsString);
+            List<string> outputStrings = await ExecuteDockerCommandAsync(context, "create", optionsString, environment);
 
             return outputStrings.FirstOrDefault();
         }
@@ -202,7 +204,7 @@ namespace GitHub.Runner.Worker.Container
             {
                 // e.g. -e MY_SECRET maps the value into the exec'ed process without exposing
                 // the value directly in the command
-                dockerOptions.Add($"-e {env.Key}");
+                dockerOptions.Add(DockerUtil.CreateEscapedOption("-e", env.Key));
             }
 
             // Watermark for GitHub Action environment
@@ -443,6 +445,11 @@ namespace GitHub.Runner.Worker.Container
         }
 
         private async Task<List<string>> ExecuteDockerCommandAsync(IExecutionContext context, string command, string options)
+        {
+            return await ExecuteDockerCommandAsync(context, command, options, null);
+        }
+
+        private async Task<List<string>> ExecuteDockerCommandAsync(IExecutionContext context, string command, string options, IDictionary<string, string> environment)
         {
             string arg = $"{command} {options}".Trim();
             context.Command($"{DockerPath} {arg}");
@@ -470,7 +477,7 @@ namespace GitHub.Runner.Worker.Container
                             workingDirectory: context.GetGitHubContext("workspace"),
                             fileName: DockerPath,
                             arguments: arg,
-                            environment: null,
+                            environment: environment,
                             requireExitCodeZero: true,
                             outputEncoding: null,
                             cancellationToken: CancellationToken.None);

src/Runner.Worker/Container/DockerUtil.cs

@@ -17,7 +17,7 @@ namespace GitHub.Runner.Worker.Container
             string pattern = $"^(?<{targetPort}>\\d+)/(?<{proto}>\\w+) -> (?<{host}>.+):(?<{hostPort}>\\d+)$";
 
             List<PortMapping> portMappings = new List<PortMapping>();
-            foreach(var line in portMappingLines)
+            foreach (var line in portMappingLines)
             {
                 Match m = Regex.Match(line, pattern, RegexOptions.None, TimeSpan.FromSeconds(1));
                 if (m.Success)
@@ -61,5 +61,19 @@ namespace GitHub.Runner.Worker.Container
             }
             return "";
         }
+
+        public static string CreateEscapedOption(string flag, string key)
+        {
+            if (String.IsNullOrEmpty(key))
+            {
+                return "";
+            }
+            return $"{flag} \"{EscapeString(key)}\"";
+        }
+
+        private static string EscapeString(string value)
+        {
+            return value.Replace("\\", "\\\\").Replace("\"", "\\\"");
+        }
     }
 }

src/Runner.Worker/ExecutionContext.cs

@@ -63,6 +63,8 @@ namespace GitHub.Runner.Worker
         // Keep track of embedded steps states
         Dictionary<Guid, Dictionary<string, string>> EmbeddedIntraActionState { get; }
 
+        IList<Issue> EmbeddedIssues { get; }
+
         bool EchoOnActionCommand { get; set; }
 
         bool IsEmbedded { get; }
@@ -91,6 +93,7 @@ namespace GitHub.Runner.Worker
         void SetOutput(string name, string value, out string reference);
         void SetTimeout(TimeSpan? timeout);
         void AddIssue(Issue issue, string message = null);
+        void AddIssueToTimelineRecord(Issue issue);
         void Progress(int percentage, string currentOperation = null);
         void UpdateDetailTimelineRecord(TimelineRecord record);
 
@@ -180,6 +183,8 @@ namespace GitHub.Runner.Worker
 
         public Dictionary<Guid, Dictionary<string, string>> EmbeddedIntraActionState { get; private set; }
 
+        public IList<Issue> EmbeddedIssues { get; } = new List<Issue>();
+
         public bool EchoOnActionCommand { get; set; }
 
         // An embedded execution context shares the same record ID, record name, and logger
@@ -369,6 +374,7 @@ namespace GitHub.Runner.Worker
             child.StepTelemetry.StepId = recordId;
             child.StepTelemetry.Stage = stage.ToString();
             child.StepTelemetry.IsEmbedded = isEmbedded;
+            child.StepTelemetry.StepContextName = child.GetFullyQualifiedContextName(); ;
 
             return child;
         }
@@ -574,7 +580,31 @@ namespace GitHub.Runner.Worker
                     long logLineNumber = Write(WellKnownTags.Error, logMessage);
                     issue.Data["logFileLineNumber"] = logLineNumber.ToString();
                 }
+            }
+            else if (issue.Type == IssueType.Warning)
+            {
+                if (!string.IsNullOrEmpty(logMessage))
+                {
+                    long logLineNumber = Write(WellKnownTags.Warning, logMessage);
+                    issue.Data["logFileLineNumber"] = logLineNumber.ToString();
+                }
+            }
+            else if (issue.Type == IssueType.Notice)
+            {
+                if (!string.IsNullOrEmpty(logMessage))
+                {
+                    long logLineNumber = Write(WellKnownTags.Notice, logMessage);
+                    issue.Data["logFileLineNumber"] = logLineNumber.ToString();
+                }
+            }
+            AddIssueToTimelineRecord(issue);
+        }
 
+        public void AddIssueToTimelineRecord(Issue issue)
+        {
+            ArgUtil.NotNull(issue, nameof(issue));
+            if (issue.Type == IssueType.Error)
+            {
                 if (_record.ErrorCount < _maxIssueCount)
                 {
                     _record.Issues.Add(issue);
@@ -584,12 +614,6 @@ namespace GitHub.Runner.Worker
             }
             else if (issue.Type == IssueType.Warning)
             {
-                if (!string.IsNullOrEmpty(logMessage))
-                {
-                    long logLineNumber = Write(WellKnownTags.Warning, logMessage);
-                    issue.Data["logFileLineNumber"] = logLineNumber.ToString();
-                }
-
                 if (_record.WarningCount < _maxIssueCount)
                 {
                     _record.Issues.Add(issue);
@@ -599,12 +623,6 @@ namespace GitHub.Runner.Worker
             }
             else if (issue.Type == IssueType.Notice)
             {
-                if (!string.IsNullOrEmpty(logMessage))
-                {
-                    long logLineNumber = Write(WellKnownTags.Notice, logMessage);
-                    issue.Data["logFileLineNumber"] = logLineNumber.ToString();
-                }
-
                 if (_record.NoticeCount < _maxIssueCount)
                 {
                     _record.Issues.Add(issue);
@@ -612,8 +630,17 @@ namespace GitHub.Runner.Worker
 
                 _record.NoticeCount++;
             }
+            // Composite actions should never upload a timeline record to the server
+            // We add these to a list and let composite action handler bubble it up recursively
+            if (this.IsEmbedded)
+            {
+                EmbeddedIssues.Add(issue);
+            }
+            else
+            {
+                _jobServerQueue.QueueTimelineRecordUpdate(_mainTimelineId, _record);
+            }
 
-            _jobServerQueue.QueueTimelineRecordUpdate(_mainTimelineId, _record);
         }
 
         public void UpdateDetailTimelineRecord(TimelineRecord record)
@@ -959,6 +986,8 @@ namespace GitHub.Runner.Worker
                         _record.StartTime != null)
                     {
                         StepTelemetry.ExecutionTimeInSeconds = (int)Math.Ceiling((_record.FinishTime - _record.StartTime)?.TotalSeconds ?? 0);
+                        StepTelemetry.StartTime = _record.StartTime;
+                        StepTelemetry.FinishTime = _record.FinishTime;
                     }
 
                     if (!IsEmbedded &&

src/Runner.Worker/Handlers/CompositeActionHandler.cs

@@ -413,6 +413,12 @@ namespace GitHub.Runner.Worker.Handlers
 
                 // Update context
                 step.ExecutionContext.UpdateGlobalStepsContext();
+
+                // Update annotations
+                foreach (var issue in step.ExecutionContext.EmbeddedIssues)
+                {
+                    ExecutionContext.AddIssueToTimelineRecord(issue);
+                }
             }
         }
 

src/Runner.Worker/Handlers/StepHost.cs

@@ -193,7 +193,7 @@ namespace GitHub.Runner.Worker.Handlers
                 TranslateToContainerPath(environment);
                 await containerHookManager.RunScriptStepAsync(context,
                                                                                    Container,
-                                                                                   workingDirectory,                                                                                   
+                                                                                   workingDirectory,
                                                                                    fileName,
                                                                                    arguments,
                                                                                    environment,
@@ -216,7 +216,7 @@ namespace GitHub.Runner.Worker.Handlers
             {
                 // e.g. -e MY_SECRET maps the value into the exec'ed process without exposing
                 // the value directly in the command
-                dockerCommandArgs.Add($"-e {env.Key}");
+                dockerCommandArgs.Add(DockerUtil.CreateEscapedOption("-e", env.Key));
             }
             if (!string.IsNullOrEmpty(PrependPath))
             {

src/Runner.Worker/JobExtension.cs

@@ -316,6 +316,29 @@ namespace GitHub.Runner.Worker
                         }
                     }
 
+                    if (message.Variables.TryGetValue("system.workflowFileFullPath", out VariableValue workflowFileFullPath))
+                    {
+                        context.Output($"Uses: {workflowFileFullPath.Value}");
+                        if (message.ContextData.TryGetValue("inputs", out var pipelineContextData))
+                        {
+                            var inputs = pipelineContextData.AssertDictionary("inputs");
+                            if (inputs.Any()) 
+                            {
+                                context.Output($"##[group] Inputs");
+                                foreach (var input in inputs) 
+                                {
+                                    context.Output($"  {input.Key}: {input.Value}");
+                                }
+                                context.Output("##[endgroup]");
+                            }
+                        }
+
+                        if (!string.IsNullOrWhiteSpace(message.JobDisplayName)) 
+                        {
+                            context.Output($"Complete job name: {message.JobDisplayName}");
+                        }
+                    }
+
                     var intraActionStates = new Dictionary<Guid, Dictionary<string, string>>();
                     foreach (var preStep in prepareResult.PreStepTracker)
                     {

src/Sdk/DTWebApi/WebApi/ActionsStepTelemetry.cs

@@ -30,6 +30,9 @@ namespace GitHub.DistributedTask.WebApi
         [DataMember(EmitDefaultValue = false)]
         public Guid StepId { get; set; }
 
+        [DataMember(EmitDefaultValue = false)]
+        public string StepContextName { get; set; }
+
         [DataMember(EmitDefaultValue = false)]
         public bool? HasRunsStep { get; set; }
 
@@ -57,6 +60,12 @@ namespace GitHub.DistributedTask.WebApi
         [DataMember(EmitDefaultValue = false)]
         public int? ExecutionTimeInSeconds { get; set; }
 
+        [DataMember(EmitDefaultValue = false)]
+        public DateTime? StartTime { get; set; }
+
+        [DataMember(EmitDefaultValue = false)]
+        public DateTime? FinishTime { get; set; }
+
         [DataMember(EmitDefaultValue = false)]
         public string ContainerHookData { get; set; }
     }

src/Test/L0/Container/DockerUtilL0.cs

@@ -144,5 +144,32 @@ namespace GitHub.Runner.Common.Tests.Worker.Container
             var actual = DockerUtil.ParseRegistryHostnameFromImageName(input);
             Assert.Equal(expected, actual);
         }
+
+        [Theory]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Worker")]
+        [InlineData("", "")]
+        [InlineData("HOME alpine:3.8 sh -c id #", "HOME alpine:3.8 sh -c id #")]
+        [InlineData("HOME \"alpine:3.8 sh -c id #", "HOME \\\"alpine:3.8 sh -c id #")]
+        [InlineData("HOME \\\"alpine:3.8 sh -c id #", "HOME \\\\\\\"alpine:3.8 sh -c id #")]
+        [InlineData("HOME \\\\\"alpine:3.8 sh -c id #", "HOME \\\\\\\\\\\"alpine:3.8 sh -c id #")]
+        [InlineData("HOME \"\"alpine:3.8 sh -c id #", "HOME \\\"\\\"alpine:3.8 sh -c id #")]
+        [InlineData("HOME \\\"\"alpine:3.8 sh -c id #", "HOME \\\\\\\"\\\"alpine:3.8 sh -c id #")]
+        [InlineData("HOME \"\\\"alpine:3.8 sh -c id #", "HOME \\\"\\\\\\\"alpine:3.8 sh -c id #")]
+        public void CreateEscapedOption_keyOnly(string input, string escaped)
+        {
+            var flag = "--example";
+            var actual = DockerUtil.CreateEscapedOption(flag, input);
+            string expected;
+            if (String.IsNullOrEmpty(input))
+            {
+                expected = "";
+            }
+            else
+            {
+                expected = $"{flag} \"{escaped}\"";
+            }
+            Assert.Equal(expected, actual);
+        }
     }
 }

src/Test/L0/Worker/ActionManifestManagerL0.cs

@@ -698,6 +698,31 @@ namespace GitHub.Runner.Common.Tests.Worker
             }
         }
 
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Worker")]
+        public void Load_CompositeActionNoUsing()
+        {
+            try
+            {
+                //Arrange
+                Setup();
+
+                var actionManifest = new ActionManifestManager();
+                actionManifest.Initialize(_hc);
+                var action_path = Path.Combine(TestUtil.GetTestDataPath(), "composite_action_without_using_token.yml");
+
+                //Assert
+                var err = Assert.Throws<ArgumentException>(() => actionManifest.Load(_ec.Object, action_path));
+                Assert.Contains($"Fail to load {action_path}", err.Message);
+                _ec.Verify(x => x.AddIssue(It.Is<Issue>(s => s.Message.Contains("Missing 'using' value. 'using' requires 'composite', 'docker', 'node12' or 'node16'.")), It.IsAny<string>()), Times.Once);
+            }
+            finally
+            {
+                Teardown();
+            }
+        }
+
         [Fact]
         [Trait("Level", "L0")]
         [Trait("Category", "Worker")]

src/Test/TestData/composite_action_without_using_token.yml

@@ -0,0 +1,9 @@
+name: "composite action"
+description: "test composite action without value for the 'using' token in 'runs'"
+
+runs:
+  steps:
+    - id: mystep
+      shell: bash
+      run: |
+        echo "hello world"

src/runnerversion

@@ -1 +1 @@
-2.295.0
+2.296.1