Runner Job Started/Completed Hooks (#1737)

* Prototype for pre job hook

* Remove debug log

* Enable hooks again

* Initialize with hostContext

* Add event_path, fix no-path bug

* Allow script post steps

* Call script handler with correct pre post stage

* Add job completed hook

* Make filecommand work and hardcode shell

* Conditionally print step details and no telemetry for hooks

* Figure out whih script to use

* Only check path for managed scripts

* Resture win dependency

* Nits

* Remove unused, add named params

* Telemetry + refactoring

* add message to job

* rename hooks remove stale comment

* cleanup

* Use .CreateService to create step

* Add L0s

* pr feedback

* update tests

* add disclaimer, clean up code

* spacing fix

* little more cleanup

* pr fix

* pr feedback

* Refactor to use JobExtension

* fix tests

* fix typo

* cleanup code

* more cleanup

* little more cleanup

* last bit of cleanup

* fix tests

* nit fix

* Update src/Runner.Worker/JobHookProvider.cs

Co-authored-by: Edward Thomson <ethomson@github.com>

* don't override runner telemtry

* pr feedback

* pr feedback

* pr feedback

Co-authored-by: Thomas Boop <thboop@github.com>
Co-authored-by: Thomas Boop <52323235+thboop@users.noreply.github.com>
Co-authored-by: Edward Thomson <ethomson@github.com>

src/Runner.Common/Constants.cs

@@ -189,6 +189,12 @@ namespace GitHub.Runner.Common
             public static readonly string Success = "success";
         }
 
+        public static class Hooks
+        {
+            public static readonly string JobStartedStepName = "Set up runner";
+            public static readonly string JobCompletedStepName = "Complete runner";
+        }
+
         public static class Path
         {
             public static readonly string ActionsDirectory = "_actions";

src/Runner.Worker/ActionRunner.cs

@@ -1,7 +1,5 @@
 using System;
 using System.Collections.Generic;
-using System.IO;
-using System.Text;
 using System.Threading.Tasks;
 using GitHub.DistributedTask.ObjectTemplating;
 using GitHub.DistributedTask.ObjectTemplating.Tokens;
@@ -11,6 +9,7 @@ using GitHub.DistributedTask.Pipelines.ObjectTemplating;
 using GitHub.Runner.Common;
 using GitHub.Runner.Common.Util;
 using GitHub.Runner.Sdk;
+using GitHub.Runner.Worker;
 using GitHub.Runner.Worker.Handlers;
 using Pipelines = GitHub.DistributedTask.Pipelines;
 
@@ -141,21 +140,7 @@ namespace GitHub.Runner.Worker
 
             IStepHost stepHost = HostContext.CreateService<IDefaultStepHost>();
 
-            // Makes directory for event_path data
+            ExecutionContext.WriteWebhookPayload();
-            var tempDirectory = HostContext.GetDirectory(WellKnownDirectory.Temp);
-            var workflowDirectory = Path.Combine(tempDirectory, "_github_workflow");
-            Directory.CreateDirectory(workflowDirectory);
-
-            var gitHubEvent = ExecutionContext.GetGitHubContext("event");
-
-            // adds the GitHub event path/file if the event exists
-            if (gitHubEvent != null)
-            {
-                var workflowFile = Path.Combine(workflowDirectory, "event.json");
-                Trace.Info($"Write event payload to {workflowFile}");
-                File.WriteAllText(workflowFile, gitHubEvent, new UTF8Encoding(false));
-                ExecutionContext.SetGitHubContext("event_path", workflowFile);
-            }
 
             // Set GITHUB_ACTION_REPOSITORY if this Action is from a repository
             if (Action.Reference is Pipelines.RepositoryPathReference repoPathReferenceAction &&

src/Runner.Worker/ExecutionContext.cs

@@ -109,6 +109,7 @@ namespace GitHub.Runner.Worker
         void ForceTaskComplete();
         void RegisterPostJobStep(IStep step);
         void PublishStepTelemetry();
+        void WriteWebhookPayload();
     }
 
     public sealed class ExecutionContext : RunnerService, IExecutionContext
@@ -991,6 +992,24 @@ namespace GitHub.Runner.Worker
             }
         }
 
+        public void WriteWebhookPayload()
+        {
+            // Makes directory for event_path data
+            var tempDirectory = HostContext.GetDirectory(WellKnownDirectory.Temp);
+            var workflowDirectory = Path.Combine(tempDirectory, "_github_workflow");
+            Directory.CreateDirectory(workflowDirectory);
+            var gitHubEvent = GetGitHubContext("event");
+
+            // adds the GitHub event path/file if the event exists
+            if (gitHubEvent != null)
+            {
+                var workflowFile = Path.Combine(workflowDirectory, "event.json");
+                Trace.Info($"Write event payload to {workflowFile}");
+                File.WriteAllText(workflowFile, gitHubEvent, new UTF8Encoding(false));
+                SetGitHubContext("event_path", workflowFile);
+            }
+        }
+
         private void InitializeTimelineRecord(Guid timelineId, Guid timelineRecordId, Guid? parentTimelineRecordId, string recordType, string displayName, string refName, int? order)
         {
             _mainTimelineId = timelineId;

src/Runner.Worker/Handlers/Handler.cs

@@ -36,6 +36,7 @@ namespace GitHub.Runner.Worker.Handlers
         protected IActionCommandManager ActionCommandManager { get; private set; }
 
         public Pipelines.ActionStepDefinitionReference Action { get; set; }
+        public bool IsActionStep => Action != null; 
         public Dictionary<string, string> Environment { get; set; }
         public Variables RuntimeVariables { get; set; }
         public IExecutionContext ExecutionContext { get; set; }
@@ -49,13 +50,18 @@ namespace GitHub.Runner.Worker.Handlers
             // Print out action details
             PrintActionDetails(stage);
 
-            // Get telemetry for the action.
+            // Get telemetry for the action
-            PopulateActionTelemetry();
+            PopulateActionTelemetry(stage);
         }
 
-        protected void PopulateActionTelemetry()
+        protected void PopulateActionTelemetry(ActionRunStage stage)
         {
-            if (Action.Type == Pipelines.ActionSourceType.ContainerRegistry)
+            if (!IsActionStep)
+            {
+                ExecutionContext.StepTelemetry.Type = "runner";
+                ExecutionContext.StepTelemetry.Action = $"{stage} Job Hook";
+            }
+            else if (Action.Type == Pipelines.ActionSourceType.ContainerRegistry)
             {
                 ExecutionContext.StepTelemetry.Type = "docker";
                 var registryAction = Action as Pipelines.ContainerRegistryReference;

src/Runner.Worker/Handlers/ScriptHandler.cs

@@ -24,16 +24,22 @@ namespace GitHub.Runner.Worker.Handlers
 
         protected override void PrintActionDetails(ActionRunStage stage)
         {
-
+            // if we're executing a Job Extension, we won't have an 'Action'
-            if (stage == ActionRunStage.Post)
+            if (!IsActionStep)
             {
-                throw new NotSupportedException("Script action should not have 'Post' job action.");
+                if (Inputs.TryGetValue("path", out var path))
+                {
+                    ExecutionContext.Output($"##[group]Run '{path}'");
                 }
-
+                else
+                {
+                    throw new InvalidOperationException("Inputs 'path' must be set for job extensions");
+                }
+            }
+            else if (Action.Type == Pipelines.ActionSourceType.Script)
+            {
                 Inputs.TryGetValue("script", out string contents);
                 contents = contents ?? string.Empty;
-            if (Action.Type == Pipelines.ActionSourceType.Script)
-            {
                 var firstLine = contents.TrimStart(' ', '\t', '\r', '\n');
                 var firstNewLine = firstLine.IndexOfAny(new[] { '\r', '\n' });
                 if (firstNewLine >= 0)
@@ -42,18 +48,17 @@ namespace GitHub.Runner.Worker.Handlers
                 }
 
                 ExecutionContext.Output($"##[group]Run {firstLine}");
-            }
-            else
-            {
-                throw new InvalidOperationException($"Invalid action type {Action.Type} for {nameof(ScriptHandler)}");
-            }
-
                 var multiLines = contents.Replace("\r\n", "\n").TrimEnd('\n').Split('\n');
                 foreach (var line in multiLines)
                 {
                     // Bright Cyan color
                     ExecutionContext.Output($"\x1b[36;1m{line}\x1b[0m");
                 }
+            }
+            else
+            {
+                throw new InvalidOperationException($"Invalid action type {Action?.Type} for {nameof(ScriptHandler)}");
+            }
 
             string argFormat;
             string shellCommand;
@@ -132,11 +137,6 @@ namespace GitHub.Runner.Worker.Handlers
 
         public async Task RunAsync(ActionRunStage stage)
         {
-            if (stage == ActionRunStage.Post)
-            {
-                throw new NotSupportedException("Script action should not have 'Post' job action.");
-            }
-
             // Validate args
             Trace.Entering();
             ArgUtil.NotNull(ExecutionContext, nameof(ExecutionContext));
@@ -212,7 +212,8 @@ namespace GitHub.Runner.Worker.Handlers
                 }
             }
 
-            if (!string.IsNullOrEmpty(shellCommand))
+            // Don't override runner telemetry here
+            if (!string.IsNullOrEmpty(shellCommand) && IsActionStep)
             {
                 ExecutionContext.StepTelemetry.Action = shellCommand;
             }
@@ -222,10 +223,24 @@ namespace GitHub.Runner.Worker.Handlers
             {
                 throw new ArgumentException("Invalid shell option. Shell must be a valid built-in (bash, sh, cmd, powershell, pwsh) or a format string containing '{0}'");
             }
-
+            string scriptFilePath, resolvedScriptPath;
+            if (IsActionStep)
+            {
                 // We do not not the full path until we know what shell is being used, so that we can determine the file extension
-            var scriptFilePath = Path.Combine(tempDirectory, $"{Guid.NewGuid()}{ScriptHandlerHelpers.GetScriptFileExtension(shellCommand)}");
+                scriptFilePath = Path.Combine(tempDirectory, $"{Guid.NewGuid()}{ScriptHandlerHelpers.GetScriptFileExtension(shellCommand)}");
-            var resolvedScriptPath = $"{StepHost.ResolvePathForStepHost(scriptFilePath).Replace("\"", "\\\"")}";
+                resolvedScriptPath = $"{StepHost.ResolvePathForStepHost(scriptFilePath).Replace("\"", "\\\"")}";
+            }
+            else
+            {
+                // JobExtensionRunners run a script file, we load that from the inputs here
+                if (!Inputs.ContainsKey("path"))
+                {
+                    throw new ArgumentException("Expected 'path' input to be set");
+                }
+                scriptFilePath = Inputs["path"];
+                ArgUtil.NotNullOrEmpty(scriptFilePath, "path");
+                resolvedScriptPath = Inputs["path"].Replace("\"", "\\\"");
+            }
 
             // Format arg string with script path
             var arguments = string.Format(argFormat, resolvedScriptPath);
@@ -242,8 +257,11 @@ namespace GitHub.Runner.Worker.Handlers
             // Don't add a BOM. It causes the script to fail on some operating systems (e.g. on Ubuntu 14).
             var encoding = new UTF8Encoding(false);
 #endif            
+            if (IsActionStep)
+            {
                 // Script is written to local path (ie host) but executed relative to the StepHost, which may be a container
                 File.WriteAllText(scriptFilePath, contents, encoding);
+            }
 
             // Prepend PATH
             AddPrependPathToEnvironment();

src/Runner.Worker/Handlers/ScriptHandlerHelpers.cs

@@ -1,6 +1,8 @@
 
 using System;
 using System.Collections.Generic;
+using System.IO;
+using GitHub.Runner.Sdk;
 
 namespace GitHub.Runner.Worker.Handlers
 {
@@ -79,5 +81,22 @@ namespace GitHub.Runner.Worker.Handlers
                 throw new ArgumentException($"Failed to parse COMMAND [..ARGS] from {shellOption}");
             }
         }
+
+        internal static string GetDefaultShellForScript(string path, Common.Tracing trace, string prependPath)
+        {
+            var format = "{0} {1}";
+            switch (Path.GetExtension(path))
+            {
+                case ".sh":
+                    // use 'sh' args but prefer bash
+                    var pathToShell = WhichUtil.Which("bash", false, trace, prependPath) ?? WhichUtil.Which("sh", true, trace, prependPath);
+                    return string.Format(format, pathToShell, _defaultArguments["sh"]);
+                case ".ps1":
+                    var pathToPowershell = WhichUtil.Which("pwsh", false, trace, prependPath) ?? WhichUtil.Which("powershell", true, trace, prependPath);
+                    return string.Format(format, pathToPowershell, _defaultArguments["powershell"]);
+                default:
+                    throw new ArgumentException($"{path} is not a valid path to a script. Make sure it ends in '.sh' or '.ps1'.");
+            }
+        }
     }
 }

src/Runner.Worker/JobExtension.cs

@@ -15,6 +15,7 @@ using GitHub.DistributedTask.WebApi;
 using GitHub.Runner.Common;
 using GitHub.Runner.Common.Util;
 using GitHub.Runner.Sdk;
+using GitHub.Runner.Worker;
 using Pipelines = GitHub.DistributedTask.Pipelines;
 
 namespace GitHub.Runner.Worker
@@ -248,6 +249,19 @@ namespace GitHub.Runner.Worker
                     Trace.Info("Downloading actions");
                     var actionManager = HostContext.GetService<IActionManager>();
                     var prepareResult = await actionManager.PrepareActionsAsync(context, message.Steps);
+
+                    // add hook to preJobSteps
+                    var startedHookPath = Environment.GetEnvironmentVariable("ACTIONS_RUNNER_HOOK_JOB_STARTED");
+                    if (!string.IsNullOrEmpty(startedHookPath))
+                    {
+                        var hookProvider = HostContext.GetService<IJobHookProvider>();
+                        var jobHookData = new JobHookData(ActionRunStage.Pre, startedHookPath);
+                        preJobSteps.Add(new JobExtensionRunner(runAsync: hookProvider.RunHook,
+                                                                          condition: $"{PipelineTemplateConstants.Always}()",
+                                                                          displayName: Constants.Hooks.JobStartedStepName,
+                                                                          data: (object)jobHookData));
+                    }
+
                     preJobSteps.AddRange(prepareResult.ContainerSetupSteps);
 
                     // Add start-container steps, record and stop-container steps
@@ -337,6 +351,18 @@ namespace GitHub.Runner.Worker
                         }
                     }
 
+                    // Register Job Completed hook if the variable is set
+                    var completedHookPath = Environment.GetEnvironmentVariable("ACTIONS_RUNNER_HOOK_JOB_COMPLETED");
+                    if (!string.IsNullOrEmpty(completedHookPath))
+                    {
+                        var hookProvider = HostContext.GetService<IJobHookProvider>();
+                        var jobHookData = new JobHookData(ActionRunStage.Post, completedHookPath);
+                        jobContext.RegisterPostJobStep(new JobExtensionRunner(runAsync: hookProvider.RunHook,
+                                                                          condition: $"{PipelineTemplateConstants.Always}()",
+                                                                          displayName: Constants.Hooks.JobCompletedStepName,
+                                                                          data: (object)jobHookData));
+                    }
+
                     List<IStep> steps = new List<IStep>();
                     steps.AddRange(preJobSteps);
                     steps.AddRange(jobSteps);

src/Runner.Worker/JobHookProvider.cs

@@ -0,0 +1,95 @@
+using System;
+using System.Collections.Generic;
+using System.IO;
+using System.Threading.Tasks;
+using System.Linq;
+using GitHub.Runner.Common;
+using GitHub.Runner.Common.Util;
+using GitHub.Runner.Sdk;
+using GitHub.Runner.Worker.Handlers;
+
+namespace GitHub.Runner.Worker
+{
+    [ServiceLocator(Default = typeof(JobHookProvider))]
+    public interface IJobHookProvider : IRunnerService
+    {
+        Task RunHook(IExecutionContext executionContext, object data);
+    }
+
+    public class JobHookData
+    {
+        public string Path {get; private set;}
+        public ActionRunStage Stage {get; private set;}
+
+        public JobHookData(ActionRunStage stage, string path)
+        {
+            Path = path;
+            Stage = stage;
+        }
+    }
+
+    public class JobHookProvider : RunnerService, IJobHookProvider
+    {
+        public override void Initialize(IHostContext hostContext)
+        {
+            base.Initialize(hostContext);
+        }
+
+        public async Task RunHook(IExecutionContext executionContext, object data)
+        {
+            // Get Inputs
+            var hookData = data as JobHookData;
+            ArgUtil.NotNull(hookData, nameof(JobHookData));
+
+            var displayName = hookData.Stage == ActionRunStage.Pre ? Constants.Hooks.JobStartedStepName : Constants.Hooks.JobCompletedStepName;
+            // Log to users so that they know how this step was injected
+            executionContext.Output($"A '{displayName}' has been configured by the self-hosted runner administrator");
+
+            // Validate script file.
+            if (!File.Exists(hookData.Path))
+            {
+                throw new FileNotFoundException("File doesn't exist");
+            }
+
+            executionContext.WriteWebhookPayload();
+
+            // Create the handler data.
+            var scriptDirectory = Path.GetDirectoryName(hookData.Path);
+            var stepHost = HostContext.CreateService<IDefaultStepHost>();
+            var prependPath = string.Join(Path.PathSeparator.ToString(), executionContext.Global.PrependPath.Reverse<string>());
+            Dictionary<string, string> inputs = new()
+            {
+                ["path"] = hookData.Path,
+                ["shell"] = ScriptHandlerHelpers.GetDefaultShellForScript(hookData.Path, Trace, prependPath)
+            };
+
+            // Create the handler
+            var handlerFactory = HostContext.GetService<IHandlerFactory>();
+            var handler = handlerFactory.Create(
+                            executionContext,
+                            action: null,
+                            stepHost,
+                            new ScriptActionExecutionData(),
+                            inputs,
+                            environment: new Dictionary<string, string>(VarUtil.EnvironmentVariableKeyComparer),
+                            executionContext.Global.Variables,
+                            actionDirectory: scriptDirectory,
+                            localActionContainerSetupSteps: null);
+            handler.PrepareExecution(hookData.Stage);
+
+            // Setup file commands
+            var fileCommandManager = HostContext.CreateService<IFileCommandManager>();
+            fileCommandManager.InitializeFiles(executionContext, null);
+
+            // Run the step and process the file commands
+            try
+            {
+                await handler.RunAsync(hookData.Stage);
+            }
+            finally
+            {
+                fileCommandManager.ProcessFiles(executionContext, executionContext.Global.Container);
+            }
+        }
+    }
+}

src/Test/L0/Worker/ActionRunnerL0.cs

@@ -118,7 +118,7 @@ namespace GitHub.Runner.Common.Tests.Worker
             await _actionRunner.RunAsync();
 
             //Assert
-            _ec.Verify(x => x.SetGitHubContext("event_path", Path.Combine(_hc.GetDirectory(WellKnownDirectory.Temp), "_github_workflow", "event.json")), Times.Once);
+            _ec.Verify(x => x.WriteWebhookPayload(), Times.Once);
         }
 
         [Fact]

src/Test/L0/Worker/JobExtensionL0.cs

@@ -25,6 +25,7 @@ namespace GitHub.Runner.Common.Tests.Worker
         private Mock<IPagingLogger> _logger;
         private Mock<IContainerOperationProvider> _containerProvider;
         private Mock<IDiagnosticLogManager> _diagnosticLogManager;
+        private Mock<IJobHookProvider> _jobHookProvider;
 
         private CancellationTokenSource _tokenSource;
         private TestHostContext CreateTestContext([CallerMemberName] String testName = "")
@@ -40,6 +41,7 @@ namespace GitHub.Runner.Common.Tests.Worker
             _directoryManager = new Mock<IPipelineDirectoryManager>();
             _directoryManager.Setup(x => x.PrepareDirectory(It.IsAny<IExecutionContext>(), It.IsAny<Pipelines.WorkspaceOptions>()))
                              .Returns(new TrackingConfig() { PipelineDirectory = "runner", WorkspaceDirectory = "runner/runner" });
+            _jobHookProvider = new Mock<IJobHookProvider>();
 
             IActionRunner step1 = new ActionRunner();
             IActionRunner step2 = new ActionRunner();
@@ -111,7 +113,9 @@ namespace GitHub.Runner.Common.Tests.Worker
             hc.SetSingleton(_containerProvider.Object);
             hc.SetSingleton(_directoryManager.Object);
             hc.SetSingleton(_diagnosticLogManager.Object);
+            hc.SetSingleton(_jobHookProvider.Object);
             hc.EnqueueInstance<IPagingLogger>(_logger.Object); // JobExecutionContext
+            hc.EnqueueInstance<IPagingLogger>(_logger.Object); // job start hook
             hc.EnqueueInstance<IPagingLogger>(_logger.Object); // Initial Job
             hc.EnqueueInstance<IPagingLogger>(_logger.Object); // step1
             hc.EnqueueInstance<IPagingLogger>(_logger.Object); // step2
@@ -120,6 +124,7 @@ namespace GitHub.Runner.Common.Tests.Worker
             hc.EnqueueInstance<IPagingLogger>(_logger.Object); // step5
             hc.EnqueueInstance<IPagingLogger>(_logger.Object); // prepare1
             hc.EnqueueInstance<IPagingLogger>(_logger.Object); // prepare2
+            hc.EnqueueInstance<IPagingLogger>(_logger.Object); // job complete hook
 
             hc.EnqueueInstance<IActionRunner>(step1);
             hc.EnqueueInstance<IActionRunner>(step2);
@@ -348,5 +353,62 @@ namespace GitHub.Runner.Common.Tests.Worker
                 Assert.Equal(TaskResult.Succeeded, _jobEc.Result);
             }
         }
+
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Worker")]
+        public async Task EnsurePreAndPostHookStepsIfEnvExists()
+        {
+            Environment.SetEnvironmentVariable("ACTIONS_RUNNER_HOOK_JOB_STARTED", "/foo/bar");
+            Environment.SetEnvironmentVariable("ACTIONS_RUNNER_HOOK_JOB_COMPLETED", "/bar/foo");
+            using (TestHostContext hc = CreateTestContext())
+            {                
+                var jobExtension = new JobExtension();
+                jobExtension.Initialize(hc);
+
+                _actionManager.Setup(x => x.PrepareActionsAsync(It.IsAny<IExecutionContext>(), It.IsAny<IEnumerable<Pipelines.JobStep>>(), It.IsAny<Guid>()))
+                              .Returns(Task.FromResult(new PrepareResult(new List<JobExtensionRunner>(), new Dictionary<Guid, IActionRunner>())));
+
+                List<IStep> result = await jobExtension.InitializeJob(_jobEc, _message);
+
+                var trace = hc.GetTrace();
+
+                var hookStart = result.First() as JobExtensionRunner;
+
+                jobExtension.FinalizeJob(_jobEc, _message, DateTime.UtcNow);
+
+                Assert.Equal(Constants.Hooks.JobStartedStepName, hookStart.DisplayName);
+                Assert.Equal(Constants.Hooks.JobCompletedStepName, (_jobEc.PostJobSteps.Last() as JobExtensionRunner).DisplayName);                
+            }
+
+            Environment.SetEnvironmentVariable("ACTIONS_RUNNER_HOOK_JOB_STARTED", null);
+            Environment.SetEnvironmentVariable("ACTIONS_RUNNER_HOOK_JOB_COMPLETED", null);
+        }
+
+        [Fact]
+        [Trait("Level", "L0")]
+        [Trait("Category", "Worker")]
+        public void EnsureNoPreAndPostHookSteps()
+        {
+            using (TestHostContext hc = CreateTestContext())
+            {
+                var jobExtension = new JobExtension();
+                jobExtension.Initialize(hc);
+
+                _message.ActionsEnvironment = null;
+
+                _jobEc = new Runner.Worker.ExecutionContext {Result = TaskResult.Succeeded};
+                _jobEc.Initialize(hc);
+                _jobEc.InitializeJob(_message, _tokenSource.Token);
+
+                var x = _jobEc.JobSteps;
+
+                jobExtension.FinalizeJob(_jobEc, _message, DateTime.UtcNow);
+
+                Assert.Equal(TaskResult.Succeeded, _jobEc.Result);
+                Assert.Equal(0, _jobEc.PostJobSteps.Count);
+            }
+        }
     }
 }