From cb19da9638790019f6e7be193cd4282311992b12 Mon Sep 17 00:00:00 2001 From: Tingluo Huang Date: Fri, 11 Feb 2022 16:18:41 -0500 Subject: [PATCH] Move JobTelemetry and StepsTelemetry into GlobalContext. (#1680) * Move JobTelemetry and StepsTelemetry into GlobalContext. * . * . --- src/Runner.Worker/ActionCommandManager.cs | 2 +- src/Runner.Worker/ExecutionContext.cs | 68 ++++++++++++---- src/Runner.Worker/GlobalContext.cs | 2 + .../Handlers/CompositeActionHandler.cs | 36 ++++----- .../Handlers/ContainerActionHandler.cs | 27 +++---- src/Runner.Worker/Handlers/Handler.cs | 80 ++++++++++--------- .../Handlers/NodeScriptActionHandler.cs | 22 +++-- src/Runner.Worker/Handlers/ScriptHandler.cs | 12 +-- src/Runner.Worker/JobRunner.cs | 9 +-- src/Test/L0/Worker/ActionCommandManagerL0.cs | 4 +- 10 files changed, 146 insertions(+), 116 deletions(-) diff --git a/src/Runner.Worker/ActionCommandManager.cs b/src/Runner.Worker/ActionCommandManager.cs index 6375db293..0bcde5f53 100644 --- a/src/Runner.Worker/ActionCommandManager.cs +++ b/src/Runner.Worker/ActionCommandManager.cs @@ -178,7 +178,7 @@ namespace GitHub.Runner.Worker Message = $"Invoked ::stopCommand:: with token: [{stopToken}]", Type = JobTelemetryType.ActionCommand }; - context.JobTelemetry.Add(telemetry); + context.Global.JobTelemetry.Add(telemetry); } if (isTokenInvalid && !allowUnsecureStopCommandTokens) diff --git a/src/Runner.Worker/ExecutionContext.cs b/src/Runner.Worker/ExecutionContext.cs index 297587466..d0028408e 100644 --- a/src/Runner.Worker/ExecutionContext.cs +++ b/src/Runner.Worker/ExecutionContext.cs @@ -15,8 +15,8 @@ using GitHub.DistributedTask.Pipelines; using GitHub.DistributedTask.Pipelines.ContextData; using GitHub.DistributedTask.Pipelines.ObjectTemplating; using GitHub.DistributedTask.WebApi; -using GitHub.Runner.Common.Util; using GitHub.Runner.Common; +using GitHub.Runner.Common.Util; using GitHub.Runner.Sdk; using GitHub.Runner.Worker.Container; using GitHub.Services.WebApi; @@ -52,8 +52,7 @@ namespace GitHub.Runner.Worker Dictionary IntraActionState { get; } Dictionary JobOutputs { get; } ActionsEnvironmentReference ActionsEnvironment { get; } - List ActionsStepsTelemetry { get; } - List JobTelemetry { get; } + ActionsStepTelemetry StepTelemetry { get; } DictionaryContextData ExpressionValues { get; } IList ExpressionFunctions { get; } JobContext JobContext { get; } @@ -109,6 +108,7 @@ namespace GitHub.Runner.Worker // others void ForceTaskComplete(); void RegisterPostJobStep(IStep step); + void PublishStepTelemetry(); } public sealed class ExecutionContext : RunnerService, IExecutionContext @@ -139,6 +139,7 @@ namespace GitHub.Runner.Worker // only job level ExecutionContext will track throttling delay. private long _totalThrottlingDelayInMilliseconds = 0; + private bool _stepTelemetryPublished = false; public Guid Id => _record.Id; public Guid EmbeddedId { get; private set; } @@ -152,8 +153,7 @@ namespace GitHub.Runner.Worker public Dictionary JobOutputs { get; private set; } public ActionsEnvironmentReference ActionsEnvironment { get; private set; } - public List ActionsStepsTelemetry { get; private set; } - public List JobTelemetry { get; private set; } + public ActionsStepTelemetry StepTelemetry { get; } = new ActionsStepTelemetry(); public DictionaryContextData ExpressionValues { get; } = new DictionaryContextData(); public IList ExpressionFunctions { get; } = new List(); @@ -273,9 +273,9 @@ namespace GitHub.Runner.Worker { Trace.Info($"'post' of '{actionRunner.DisplayName}' already push to child post step stack."); } - else + else { - Root.EmbeddedStepsWithPostRegistered[actionRunner.Action.Id] = actionRunner.Condition; + Root.EmbeddedStepsWithPostRegistered[actionRunner.Action.Id] = actionRunner.Condition; } return; } @@ -294,7 +294,20 @@ namespace GitHub.Runner.Worker Root.PostJobSteps.Push(step); } - public IExecutionContext CreateChild(Guid recordId, string displayName, string refName, string scopeName, string contextName, ActionRunStage stage, Dictionary intraActionState = null, int? recordOrder = null, IPagingLogger logger = null, bool isEmbedded = false, CancellationTokenSource cancellationTokenSource = null, Guid embeddedId = default(Guid), string siblingScopeName = null) + public IExecutionContext CreateChild( + Guid recordId, + string displayName, + string refName, + string scopeName, + string contextName, + ActionRunStage stage, + Dictionary intraActionState = null, + int? recordOrder = null, + IPagingLogger logger = null, + bool isEmbedded = false, + CancellationTokenSource cancellationTokenSource = null, + Guid embeddedId = default(Guid), + string siblingScopeName = null) { Trace.Entering(); @@ -306,7 +319,6 @@ namespace GitHub.Runner.Worker child.Stage = stage; child.EmbeddedId = embeddedId; child.SiblingScopeName = siblingScopeName; - child.JobTelemetry = JobTelemetry; if (intraActionState == null) { child.IntraActionState = new Dictionary(StringComparer.OrdinalIgnoreCase); @@ -354,7 +366,13 @@ namespace GitHub.Runner.Worker /// An embedded execution context shares the same record ID, record name, logger, /// and a linked cancellation token. /// - public IExecutionContext CreateEmbeddedChild(string scopeName, string contextName, Guid embeddedId, ActionRunStage stage, Dictionary intraActionState = null, string siblingScopeName = null) + public IExecutionContext CreateEmbeddedChild( + string scopeName, + string contextName, + Guid embeddedId, + ActionRunStage stage, + Dictionary intraActionState = null, + string siblingScopeName = null) { return Root.CreateChild(_record.Id, _record.Name, _record.Id.ToString("N"), scopeName, contextName, stage, logger: _logger, isEmbedded: true, cancellationTokenSource: CancellationTokenSource.CreateLinkedTokenSource(_cancellationTokenSource.Token), intraActionState: intraActionState, embeddedId: embeddedId, siblingScopeName: siblingScopeName); } @@ -404,6 +422,8 @@ namespace GitHub.Runner.Worker } } + PublishStepTelemetry(); + if (Root != this) { // only dispose TokenSource for step level ExecutionContext @@ -654,16 +674,18 @@ namespace GitHub.Runner.Worker // Job defaults shared across all actions Global.JobDefaults = new Dictionary>(StringComparer.OrdinalIgnoreCase); + // Job Telemetry + Global.JobTelemetry = new List(); + + // ActionsStepTelemetry for entire job + Global.StepsTelemetry = new List(); + // Job Outputs JobOutputs = new Dictionary(StringComparer.OrdinalIgnoreCase); // Actions environment ActionsEnvironment = message.ActionsEnvironment; - // ActionsStepTelemetry - ActionsStepsTelemetry = new List(); - - JobTelemetry = new List(); // Service container info Global.ServiceContainers = new List(); @@ -895,6 +917,24 @@ namespace GitHub.Runner.Worker return Root._matchers ?? Array.Empty(); } + public void PublishStepTelemetry() + { + if (!_stepTelemetryPublished) + { + // Add to the global steps telemetry only if we have something to log. + if (!string.IsNullOrEmpty(StepTelemetry?.Type)) + { + Trace.Info($"Publish step telemetry for current step {StringUtil.ConvertToJson(StepTelemetry)}."); + Global.StepsTelemetry.Add(StepTelemetry); + _stepTelemetryPublished = true; + } + } + else + { + Trace.Info($"Step telemetry has already been published."); + } + } + private void InitializeTimelineRecord(Guid timelineId, Guid timelineRecordId, Guid? parentTimelineRecordId, string recordType, string displayName, string refName, int? order) { _mainTimelineId = timelineId; diff --git a/src/Runner.Worker/GlobalContext.cs b/src/Runner.Worker/GlobalContext.cs index b740e10bd..b79092da0 100644 --- a/src/Runner.Worker/GlobalContext.cs +++ b/src/Runner.Worker/GlobalContext.cs @@ -14,6 +14,8 @@ namespace GitHub.Runner.Worker public PlanFeatures Features { get; set; } public IList FileTable { get; set; } public IDictionary> JobDefaults { get; set; } + public List StepsTelemetry { get; set; } + public List JobTelemetry { get; set; } public TaskOrchestrationPlanReference Plan { get; set; } public List PrependPath { get; set; } public List ServiceContainers { get; set; } diff --git a/src/Runner.Worker/Handlers/CompositeActionHandler.cs b/src/Runner.Worker/Handlers/CompositeActionHandler.cs index fa39f7f43..065a5fac8 100644 --- a/src/Runner.Worker/Handlers/CompositeActionHandler.cs +++ b/src/Runner.Worker/Handlers/CompositeActionHandler.cs @@ -42,7 +42,7 @@ namespace GitHub.Runner.Worker.Handlers { ArgUtil.NotNull(Data.PreSteps, nameof(Data.PreSteps)); steps = Data.PreSteps; - } + } else if (stage == ActionRunStage.Post) { ArgUtil.NotNull(Data.PostSteps, nameof(Data.PostSteps)); @@ -60,7 +60,7 @@ namespace GitHub.Runner.Worker.Handlers Trace.Info($"Skipping executing post step id: {step.Id}, name: ${step.DisplayName}"); } } - } + } else { ArgUtil.NotNull(Data.Steps, nameof(Data.Steps)); @@ -83,20 +83,17 @@ namespace GitHub.Runner.Worker.Handlers hasUsesStep = true; } } - var pathReference = Action as Pipelines.RepositoryPathReference; - var telemetry = new ActionsStepTelemetry { - Ref = GetActionRef(), - HasPreStep = Data.HasPre, - HasPostStep = Data.HasPost, - IsEmbedded = ExecutionContext.IsEmbedded, - Type = "composite", - HasRunsStep = hasRunsStep, - HasUsesStep = hasUsesStep, - StepCount = steps.Count - }; - ExecutionContext.Root.ActionsStepsTelemetry.Add(telemetry); + + ExecutionContext.StepTelemetry.Ref = GetActionRef(); + ExecutionContext.StepTelemetry.HasPreStep = Data.HasPre; + ExecutionContext.StepTelemetry.HasPostStep = Data.HasPost; + ExecutionContext.StepTelemetry.IsEmbedded = ExecutionContext.IsEmbedded; + ExecutionContext.StepTelemetry.Type = "composite"; + ExecutionContext.StepTelemetry.HasRunsStep = hasRunsStep; + ExecutionContext.StepTelemetry.HasUsesStep = hasUsesStep; + ExecutionContext.StepTelemetry.StepCount = steps.Count; } - + try { // Inputs of the composite step @@ -117,7 +114,7 @@ namespace GitHub.Runner.Worker.Handlers // Create embedded steps var embeddedSteps = new List(); - // If we need to setup containers beforehand, do it + // If we need to setup containers beforehand, do it // only relevant for local composite actions that need to JIT download/setup containers if (LocalActionContainerSetupSteps != null && LocalActionContainerSetupSteps.Count > 0) { @@ -152,7 +149,7 @@ namespace GitHub.Runner.Worker.Handlers } else { - step.ExecutionContext.ExpressionValues["steps"] = ExecutionContext.Global.StepsContext.GetScope(childScopeName); + step.ExecutionContext.ExpressionValues["steps"] = ExecutionContext.Global.StepsContext.GetScope(childScopeName); } // Shallow copy github context @@ -309,7 +306,7 @@ namespace GitHub.Runner.Worker.Handlers // Mark job as cancelled ExecutionContext.Root.Result = TaskResult.Canceled; ExecutionContext.Root.JobContext.Status = ExecutionContext.Root.Result?.ToActionResult(); - + step.ExecutionContext.Debug($"Re-evaluate condition on job cancellation for step: '{step.DisplayName}'."); var conditionReTestTraceWriter = new ConditionTraceWriter(Trace, null); // host tracing only var conditionReTestResult = false; @@ -393,7 +390,7 @@ namespace GitHub.Runner.Worker.Handlers { await RunStepAsync(step); } - + } finally { @@ -458,6 +455,7 @@ namespace GitHub.Runner.Worker.Handlers Trace.Info($"Step result: {step.ExecutionContext.Result}"); step.ExecutionContext.Debug($"Finished: {step.DisplayName}"); + step.ExecutionContext.PublishStepTelemetry(); } private void SetStepConclusion(IStep step, TaskResult result) diff --git a/src/Runner.Worker/Handlers/ContainerActionHandler.cs b/src/Runner.Worker/Handlers/ContainerActionHandler.cs index a74275ba1..6c13ee981 100644 --- a/src/Runner.Worker/Handlers/ContainerActionHandler.cs +++ b/src/Runner.Worker/Handlers/ContainerActionHandler.cs @@ -1,14 +1,14 @@ -using System.Collections.Generic; +using System; +using System.Collections.Generic; using System.IO; +using System.Linq; using System.Threading.Tasks; -using System; -using GitHub.Runner.Worker.Container; -using Pipelines = GitHub.DistributedTask.Pipelines; +using GitHub.DistributedTask.Pipelines.ContextData; +using GitHub.DistributedTask.WebApi; using GitHub.Runner.Common; using GitHub.Runner.Sdk; -using GitHub.DistributedTask.WebApi; -using GitHub.DistributedTask.Pipelines.ContextData; -using System.Linq; +using GitHub.Runner.Worker.Container; +using Pipelines = GitHub.DistributedTask.Pipelines; namespace GitHub.Runner.Worker.Handlers { @@ -73,14 +73,11 @@ namespace GitHub.Runner.Worker.Handlers // Add Telemetry to JobContext to send with JobCompleteMessage if (stage == ActionRunStage.Main) { - var telemetry = new ActionsStepTelemetry { - Ref = GetActionRef(), - HasPreStep = Data.HasPre, - HasPostStep = Data.HasPost, - IsEmbedded = ExecutionContext.IsEmbedded, - Type = type - }; - ExecutionContext.Root.ActionsStepsTelemetry.Add(telemetry); + ExecutionContext.StepTelemetry.Ref = GetActionRef(); + ExecutionContext.StepTelemetry.HasPreStep = Data.HasPre; + ExecutionContext.StepTelemetry.HasPostStep = Data.HasPost; + ExecutionContext.StepTelemetry.IsEmbedded = ExecutionContext.IsEmbedded; + ExecutionContext.StepTelemetry.Type = type; } // run container diff --git a/src/Runner.Worker/Handlers/Handler.cs b/src/Runner.Worker/Handlers/Handler.cs index bd70c0d8e..9290ad3a1 100644 --- a/src/Runner.Worker/Handlers/Handler.cs +++ b/src/Runner.Worker/Handlers/Handler.cs @@ -1,13 +1,13 @@ -using GitHub.DistributedTask.WebApi; -using GitHub.Runner.Common.Util; using System; using System.Collections.Generic; -using System.Threading.Tasks; -using System.Linq; using System.IO; -using Pipelines = GitHub.DistributedTask.Pipelines; +using System.Linq; +using System.Threading.Tasks; +using GitHub.DistributedTask.WebApi; using GitHub.Runner.Common; +using GitHub.Runner.Common.Util; using GitHub.Runner.Sdk; +using Pipelines = GitHub.DistributedTask.Pipelines; namespace GitHub.Runner.Worker.Handlers { @@ -44,42 +44,10 @@ namespace GitHub.Runner.Worker.Handlers public string ActionDirectory { get; set; } public List LocalActionContainerSetupSteps { get; set; } - public virtual string GetActionRef() - { - if (Action.Type == Pipelines.ActionSourceType.ContainerRegistry) - { - var registryAction = Action as Pipelines.ContainerRegistryReference; - return registryAction.Image; - } - else if (Action.Type == Pipelines.ActionSourceType.Repository) - { - var repoAction = Action as Pipelines.RepositoryPathReference; - if (string.Equals(repoAction.RepositoryType, Pipelines.PipelineConstants.SelfAlias, StringComparison.OrdinalIgnoreCase)) - { - return repoAction.Path; - } - else - { - if (string.IsNullOrEmpty(repoAction.Path)) - { - return $"{repoAction.Name}@{repoAction.Ref}"; - } - else - { - return $"{repoAction.Name}/{repoAction.Path}@{repoAction.Ref}"; - } - } - } - else - { - // this should never happen - Trace.Error($"Can't generate ref for {Action.Type.ToString()}"); - } - return ""; - } + public virtual void PrintActionDetails(ActionRunStage stage) { - + if (stage == ActionRunStage.Post) { ExecutionContext.Output($"Post job cleanup."); @@ -150,6 +118,40 @@ namespace GitHub.Runner.Worker.Handlers ActionCommandManager = hostContext.CreateService(); } + protected string GetActionRef() + { + if (Action.Type == Pipelines.ActionSourceType.ContainerRegistry) + { + var registryAction = Action as Pipelines.ContainerRegistryReference; + return registryAction.Image; + } + else if (Action.Type == Pipelines.ActionSourceType.Repository) + { + var repoAction = Action as Pipelines.RepositoryPathReference; + if (string.Equals(repoAction.RepositoryType, Pipelines.PipelineConstants.SelfAlias, StringComparison.OrdinalIgnoreCase)) + { + return repoAction.Path; + } + else + { + if (string.IsNullOrEmpty(repoAction.Path)) + { + return $"{repoAction.Name}@{repoAction.Ref}"; + } + else + { + return $"{repoAction.Name}/{repoAction.Path}@{repoAction.Ref}"; + } + } + } + else + { + // this should never happen + Trace.Error($"Can't generate ref for {Action.Type.ToString()}"); + } + return ""; + } + protected void AddInputsToEnvironment() { // Validate args. diff --git a/src/Runner.Worker/Handlers/NodeScriptActionHandler.cs b/src/Runner.Worker/Handlers/NodeScriptActionHandler.cs index 9ea6d12d8..0b490e24c 100644 --- a/src/Runner.Worker/Handlers/NodeScriptActionHandler.cs +++ b/src/Runner.Worker/Handlers/NodeScriptActionHandler.cs @@ -1,12 +1,12 @@ -using System.IO; +using System; +using System.IO; +using System.Linq; using System.Text; using System.Threading.Tasks; +using GitHub.DistributedTask.WebApi; using GitHub.Runner.Common; using GitHub.Runner.Sdk; -using GitHub.DistributedTask.WebApi; using Pipelines = GitHub.DistributedTask.Pipelines; -using System; -using System.Linq; namespace GitHub.Runner.Worker.Handlers { @@ -77,15 +77,11 @@ namespace GitHub.Runner.Worker.Handlers // Add Telemetry to JobContext to send with JobCompleteMessage if (stage == ActionRunStage.Main) { - var telemetry = new ActionsStepTelemetry - { - Ref = GetActionRef(), - HasPreStep = Data.HasPre, - HasPostStep = Data.HasPost, - IsEmbedded = ExecutionContext.IsEmbedded, - Type = Data.NodeVersion - }; - ExecutionContext.Root.ActionsStepsTelemetry.Add(telemetry); + ExecutionContext.StepTelemetry.Ref = GetActionRef(); + ExecutionContext.StepTelemetry.HasPreStep = Data.HasPre; + ExecutionContext.StepTelemetry.HasPostStep = Data.HasPost; + ExecutionContext.StepTelemetry.IsEmbedded = ExecutionContext.IsEmbedded; + ExecutionContext.StepTelemetry.Type = Data.NodeVersion; } ArgUtil.NotNullOrEmpty(target, nameof(target)); diff --git a/src/Runner.Worker/Handlers/ScriptHandler.cs b/src/Runner.Worker/Handlers/ScriptHandler.cs index da395c27a..de7f1a931 100644 --- a/src/Runner.Worker/Handlers/ScriptHandler.cs +++ b/src/Runner.Worker/Handlers/ScriptHandler.cs @@ -1,12 +1,12 @@ using System; using System.IO; +using System.Linq; using System.Text; using System.Threading.Tasks; -using System.Linq; using GitHub.DistributedTask.Pipelines.ContextData; +using GitHub.DistributedTask.WebApi; using GitHub.Runner.Common; using GitHub.Runner.Sdk; -using GitHub.DistributedTask.WebApi; using Pipelines = GitHub.DistributedTask.Pipelines; namespace GitHub.Runner.Worker.Handlers @@ -147,12 +147,8 @@ namespace GitHub.Runner.Worker.Handlers // Add Telemetry to JobContext to send with JobCompleteMessage if (stage == ActionRunStage.Main) { - var telemetry = new ActionsStepTelemetry - { - IsEmbedded = ExecutionContext.IsEmbedded, - Type = "run", - }; - ExecutionContext.Root.ActionsStepsTelemetry.Add(telemetry); + ExecutionContext.StepTelemetry.IsEmbedded = ExecutionContext.IsEmbedded; + ExecutionContext.StepTelemetry.Type = "run"; } var tempDirectory = HostContext.GetDirectory(WellKnownDirectory.Temp); diff --git a/src/Runner.Worker/JobRunner.cs b/src/Runner.Worker/JobRunner.cs index 233be5515..944931534 100644 --- a/src/Runner.Worker/JobRunner.cs +++ b/src/Runner.Worker/JobRunner.cs @@ -279,14 +279,13 @@ namespace GitHub.Runner.Worker } // Load any upgrade telemetry - LoadFromTelemetryFile(jobContext.JobTelemetry); + LoadFromTelemetryFile(jobContext.Global.JobTelemetry); // Make sure we don't submit secrets as telemetry - MaskTelemetrySecrets(jobContext.JobTelemetry); - - Trace.Info("Raising job completed event."); - var jobCompletedEvent = new JobCompletedEvent(message.RequestId, message.JobId, result, jobContext.JobOutputs, jobContext.ActionsEnvironment, jobContext.ActionsStepsTelemetry, jobContext.JobTelemetry); + MaskTelemetrySecrets(jobContext.Global.JobTelemetry); + var jobCompletedEvent = new JobCompletedEvent(message.RequestId, message.JobId, result, jobContext.JobOutputs, jobContext.ActionsEnvironment, jobContext.Global.StepsTelemetry, jobContext.Global.JobTelemetry); + Trace.Info($"Raising job completed event: {StringUtil.ConvertToJson(jobCompletedEvent)}"); var completeJobRetryLimit = 5; var exceptions = new List(); diff --git a/src/Test/L0/Worker/ActionCommandManagerL0.cs b/src/Test/L0/Worker/ActionCommandManagerL0.cs index cb53a6816..cc74397e2 100644 --- a/src/Test/L0/Worker/ActionCommandManagerL0.cs +++ b/src/Test/L0/Worker/ActionCommandManagerL0.cs @@ -121,6 +121,7 @@ namespace GitHub.Runner.Common.Tests.Worker using (TestHostContext hc = CreateTestContext()) { _ec.Object.Global.EnvironmentVariables = new Dictionary(); + _ec.Object.Global.JobTelemetry = new List(); var expressionValues = new DictionaryContextData { ["env"] = @@ -131,7 +132,6 @@ namespace GitHub.Runner.Common.Tests.Worker #endif }; _ec.Setup(x => x.ExpressionValues).Returns(expressionValues); - _ec.Setup(x => x.JobTelemetry).Returns(new List()); Assert.True(_commandManager.TryProcessCommand(_ec.Object, $"::stop-commands::{invalidToken}", null)); } @@ -148,8 +148,8 @@ namespace GitHub.Runner.Common.Tests.Worker using (TestHostContext hc = CreateTestContext()) { _ec.Object.Global.EnvironmentVariables = new Dictionary(); + _ec.Object.Global.JobTelemetry = new List(); _ec.Setup(x => x.ExpressionValues).Returns(GetExpressionValues()); - _ec.Setup(x => x.JobTelemetry).Returns(new List()); Assert.Throws(() => _commandManager.TryProcessCommand(_ec.Object, $"::stop-commands::{invalidToken}", null)); } }