Do not fail service containers without the healthcheck

This reverts commit fec24e8341.

releaseNote.md

@@ -1,11 +1,9 @@
-## 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)
+- Avoid key based command injection via Docker command arguments (#2062)
-- Fixed runner update bug caused by `update.sh|cmd` running too long (#2044) 
 ## Misc
-- Bump Newtonsoft.Json from 11.0.2 to 13.0.1 (#2012)
+- Added step context name and start/finish time in step telemetry (#2069)
-- Change a periodic token expiry log message level from `WARNING` to `VERBOSE` (#2021)
+- Improved error logs when there is a missing 'using' token configuration in the metadata file  (#2052)
+- Added full job name and nested workflow details in log (#2049)
 
 ## 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 +30,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/ContainerInfo.cs

@@ -92,6 +92,8 @@ namespace GitHub.Runner.Worker.Container
         public bool IsJobContainer { get; set; }
         public bool IsAlpine { get; set; }
 
+        public bool FailedInitialization { get; set; }
+
         public IDictionary<string, string> ContainerEnvironmentVariables
         {
             get

src/Runner.Worker/Container/DockerCommandManager.cs

@@ -131,11 +131,11 @@ 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("\"", "\\\"")}\"");
+                    dockerOptions.Add(DockerUtil.CreateEscapedOption("-e", env.Key, env.Value));
                 }
             }
 
@@ -202,7 +202,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

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,28 @@ namespace GitHub.Runner.Worker.Container
             }
             return "";
         }
+
+        public static string CreateEscapedOption(string flag, string key)
+        {
+            if (String.IsNullOrEmpty(key))
+            {
+                return "";
+            }
+            return $"{flag} \"{EscapeString(key)}\"";
+        }
+
+        public static string CreateEscapedOption(string flag, string key, string value)
+        {
+            if (String.IsNullOrEmpty(key))
+            {
+                return "";
+            }
+            return $"{flag} \"{EscapeString(key)}={EscapeString(value)}\"";
+        }
+
+        private static string EscapeString(string value)
+        {
+            return value.Replace("\\", "\\\\").Replace("\"", "\\\"");
+        }
     }
 }

src/Runner.Worker/ContainerOperationProvider.cs

@@ -98,12 +98,41 @@ namespace GitHub.Runner.Worker
                 await StartContainerAsync(executionContext, container);
             }
 
+            await RunContainersHealthcheck(executionContext, containers);
+        }
+
+        public async Task RunContainersHealthcheck(IExecutionContext executionContext, List<ContainerInfo> containers)
+        {
             executionContext.Output("##[group]Waiting for all services to be ready");
+
+            var unhealthyContainers = new List<ContainerInfo>();
             foreach (var container in containers.Where(c => !c.IsJobContainer))
             {
-                await ContainerHealthcheck(executionContext, container);
+                var healthcheck = await ContainerHealthcheck(executionContext, container);
+
+                if (!(string.Equals(healthcheck, "healthy", StringComparison.OrdinalIgnoreCase) || string.IsNullOrEmpty(healthcheck)))
+                {
+                    unhealthyContainers.Add(container);
+                }
+                else
+                {
+                    executionContext.Output($"{container.ContainerNetworkAlias} service is healthy.");
+                }
             }
             executionContext.Output("##[endgroup]");
+
+            if (unhealthyContainers.Count > 0)
+            {
+                foreach (var container in unhealthyContainers)
+                {
+                    executionContext.Output($"##[group]Service container {container.ContainerNetworkAlias} failed.");
+                    await _dockerManager.DockerLogs(context: executionContext, containerId: container.ContainerId);
+                    executionContext.Error($"Failed to initialize container {container.ContainerImage}");
+                    container.FailedInitialization = true;
+                    executionContext.Output("##[endgroup]");
+                }
+                throw new InvalidOperationException("One or more containers failed to start.");
+            }
         }
 
         public async Task StopContainersAsync(IExecutionContext executionContext, object data)
@@ -299,9 +328,8 @@ namespace GitHub.Runner.Worker
 
             if (!string.IsNullOrEmpty(container.ContainerId))
             {
-                if (!container.IsJobContainer)
+                if (!container.IsJobContainer && !container.FailedInitialization)
                 {
-                    // Print logs for service container jobs (not the "action" job itself b/c that's already logged).
                     executionContext.Output($"Print service container logs: {container.ContainerDisplayName}");
 
                     int logsExitCode = await _dockerManager.DockerLogs(executionContext, container.ContainerId);
@@ -395,14 +423,14 @@ namespace GitHub.Runner.Worker
             }
         }
 
-        private async Task ContainerHealthcheck(IExecutionContext executionContext, ContainerInfo container)
+        private async Task<string> ContainerHealthcheck(IExecutionContext executionContext, ContainerInfo container)
         {
             string healthCheck = "--format=\"{{if .Config.Healthcheck}}{{print .State.Health.Status}}{{end}}\"";
             string serviceHealth = (await _dockerManager.DockerInspect(context: executionContext, dockerObject: container.ContainerId, options: healthCheck)).FirstOrDefault();
             if (string.IsNullOrEmpty(serviceHealth))
             {
                 // Container has no HEALTHCHECK
-                return;
+                return String.Empty;
             }
             var retryCount = 0;
             while (string.Equals(serviceHealth, "starting", StringComparison.OrdinalIgnoreCase))
@@ -413,14 +441,7 @@ namespace GitHub.Runner.Worker
                 serviceHealth = (await _dockerManager.DockerInspect(context: executionContext, dockerObject: container.ContainerId, options: healthCheck)).FirstOrDefault();
                 retryCount++;
             }
-            if (string.Equals(serviceHealth, "healthy", StringComparison.OrdinalIgnoreCase))
+            return serviceHealth;
-            {
-                executionContext.Output($"{container.ContainerNetworkAlias} service is healthy.");
-            }
-            else
-            {
-                throw new InvalidOperationException($"Failed to initialize, {container.ContainerNetworkAlias} service is {serviceHealth}.");
-            }
         }
 
         private async Task<string> ContainerRegistryLogin(IExecutionContext executionContext, ContainerInfo container)

src/Runner.Worker/ExecutionContext.cs

@@ -369,6 +369,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;
         }
@@ -959,6 +960,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/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,59 @@ 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);
+        }
+
+        [Theory]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Worker")]
+        [InlineData("HOME", "", "HOME", "")]
+        [InlineData("HOME alpine:3.8 sh -c id #", "HOME alpine:3.8 sh -c id #", "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 #", "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 #", "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 #", "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 #", "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 #", "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 #", "HOME \\\"\\\\\\\"alpine:3.8 sh -c id #", "HOME \\\"\\\\\\\"alpine:3.8 sh -c id #")]
+        public void CreateEscapedOption_keyValue(string keyInput, string valueInput, string escapedKey, string escapedValue)
+        {
+            var flag = "--example";
+            var actual = DockerUtil.CreateEscapedOption(flag, keyInput, valueInput);
+            string expected;
+            if (String.IsNullOrEmpty(keyInput))
+            {
+                expected = "";
+            }
+            else
+            {
+                expected = $"{flag} \"{escapedKey}={escapedValue}\"";
+            }
+            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/L0/Worker/ContainerOperationProviderL0.cs

@@ -0,0 +1,126 @@
+using GitHub.Runner.Worker;
+using GitHub.Runner.Worker.Container;
+using Xunit;
+using Moq;
+using GitHub.Runner.Worker.Container.ContainerHooks;
+using System.Threading.Tasks;
+using System.Collections.Generic;
+using System.Runtime.CompilerServices;
+using GitHub.DistributedTask.WebApi;
+using System;
+
+namespace GitHub.Runner.Common.Tests.Worker
+{
+
+    public sealed class ContainerOperationProviderL0
+    {
+
+        private TestHostContext _hc;
+        private Mock<IExecutionContext> _ec;
+        private Mock<IDockerCommandManager> _dockerManager;
+        private Mock<IContainerHookManager> _containerHookManager;
+        private ContainerOperationProvider containerOperationProvider;
+        private Mock<IJobServerQueue> serverQueue;
+        private Mock<IPagingLogger> pagingLogger;
+        private List<string> healthyDockerStatus = new List<string> { "healthy" };
+        private List<string> emptyDockerStatus = new List<string> { string.Empty };
+        private List<string> unhealthyDockerStatus = new List<string> { "unhealthy" };
+        private List<string> dockerLogs = new List<string> { "log1", "log2", "log3" };
+
+        List<ContainerInfo> containers = new List<ContainerInfo>();
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Worker")]
+        public async void RunServiceContainersHealthcheck_UnhealthyServiceContainer_AssertFailedTask()
+        {
+            //Arrange
+            Setup();
+            _dockerManager.Setup(x => x.DockerInspect(_ec.Object, It.IsAny<string>(), It.IsAny<string>())).Returns(Task.FromResult(unhealthyDockerStatus));
+
+            //Act
+            try
+            {
+                await containerOperationProvider.RunContainersHealthcheck(_ec.Object, containers);
+            }
+            catch (InvalidOperationException)
+            {
+
+                //Assert
+                Assert.Equal(TaskResult.Failed, _ec.Object.Result ?? TaskResult.Failed);
+            }
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Worker")]
+        public async void RunServiceContainersHealthcheck_UnhealthyServiceContainer_AssertExceptionThrown()
+        {
+            //Arrange
+            Setup();
+            _dockerManager.Setup(x => x.DockerInspect(_ec.Object, It.IsAny<string>(), It.IsAny<string>())).Returns(Task.FromResult(unhealthyDockerStatus));
+
+            //Act and Assert
+            await Assert.ThrowsAsync<InvalidOperationException>(() => containerOperationProvider.RunContainersHealthcheck(_ec.Object, containers));
+
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Worker")]
+        public async void RunServiceContainersHealthcheck_healthyServiceContainer_AssertSucceededTask()
+        {
+            //Arrange
+            Setup();
+            _dockerManager.Setup(x => x.DockerInspect(_ec.Object, It.IsAny<string>(), It.IsAny<string>())).Returns(Task.FromResult(healthyDockerStatus));
+
+            //Act
+            await containerOperationProvider.RunContainersHealthcheck(_ec.Object, containers);
+
+            //Assert
+            Assert.Equal(TaskResult.Succeeded, _ec.Object.Result ?? TaskResult.Succeeded);
+
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Worker")]
+        public async void RunServiceContainersHealthcheck_healthyServiceContainerWithoutHealthcheck_AssertSucceededTask()
+        {
+            //Arrange
+            Setup();
+            _dockerManager.Setup(x => x.DockerInspect(_ec.Object, It.IsAny<string>(), It.IsAny<string>())).Returns(Task.FromResult(emptyDockerStatus));
+
+            //Act
+            await containerOperationProvider.RunContainersHealthcheck(_ec.Object, containers);
+
+            //Assert
+            Assert.Equal(TaskResult.Succeeded, _ec.Object.Result ?? TaskResult.Succeeded);
+
+        }
+
+        private void Setup([CallerMemberName] string testName = "")
+        {
+            containers.Add(new ContainerInfo() { ContainerImage = "ubuntu:16.04" });
+            _hc = new TestHostContext(this, testName);
+            _ec = new Mock<IExecutionContext>();
+            serverQueue = new Mock<IJobServerQueue>();
+            pagingLogger = new Mock<IPagingLogger>();
+
+            _dockerManager = new Mock<IDockerCommandManager>();
+            _containerHookManager = new Mock<IContainerHookManager>();
+            containerOperationProvider = new ContainerOperationProvider();
+
+            _hc.SetSingleton<IDockerCommandManager>(_dockerManager.Object);
+            _hc.SetSingleton<IJobServerQueue>(serverQueue.Object);
+            _hc.SetSingleton<IPagingLogger>(pagingLogger.Object);
+
+            _hc.SetSingleton<IDockerCommandManager>(_dockerManager.Object);
+            _hc.SetSingleton<IContainerHookManager>(_containerHookManager.Object);
+
+            _ec.Setup(x => x.Global).Returns(new GlobalContext());
+
+            containerOperationProvider.Initialize(_hc);
+        }
+    }
+}

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.0