diff --git a/src/Runner.Common/JobServerQueue.cs b/src/Runner.Common/JobServerQueue.cs index 57ba3eb23..d494645f1 100644 --- a/src/Runner.Common/JobServerQueue.cs +++ b/src/Runner.Common/JobServerQueue.cs @@ -756,17 +756,17 @@ namespace GitHub.Runner.Common timelineRecord.State = rec.State ?? timelineRecord.State; timelineRecord.WorkerName = rec.WorkerName ?? timelineRecord.WorkerName; - if (rec.ErrorCount != null && rec.ErrorCount > 0) + if (rec.ErrorCount > 0) { timelineRecord.ErrorCount = rec.ErrorCount; } - if (rec.WarningCount != null && rec.WarningCount > 0) + if (rec.WarningCount > 0) { timelineRecord.WarningCount = rec.WarningCount; } - if (rec.NoticeCount != null && rec.NoticeCount > 0) + if (rec.NoticeCount > 0) { timelineRecord.NoticeCount = rec.NoticeCount; } @@ -797,7 +797,7 @@ namespace GitHub.Runner.Common foreach (var record in mergedRecords) { Trace.Verbose($" Record: t={record.RecordType}, n={record.Name}, s={record.State}, st={record.StartTime}, {record.PercentComplete}%, ft={record.FinishTime}, r={record.Result}: {record.CurrentOperation}"); - if (record.Issues != null && record.Issues.Count > 0) + if (record.Issues != null) { foreach (var issue in record.Issues) { @@ -807,7 +807,7 @@ namespace GitHub.Runner.Common } } - if (record.Variables != null && record.Variables.Count > 0) + if (record.Variables != null) { foreach (var variable in record.Variables) { diff --git a/src/Runner.Worker/ActionCommandManager.cs b/src/Runner.Worker/ActionCommandManager.cs index 33fab1f21..66cab8f8b 100644 --- a/src/Runner.Worker/ActionCommandManager.cs +++ b/src/Runner.Worker/ActionCommandManager.cs @@ -1,4 +1,4 @@ -using GitHub.DistributedTask.Pipelines.ContextData; +using GitHub.DistributedTask.Pipelines.ContextData; using GitHub.DistributedTask.WebApi; using GitHub.Runner.Worker.Container; using System; @@ -276,7 +276,7 @@ namespace GitHub.Runner.Worker Message = $"Can't update {blocked} environment variable using ::set-env:: command." }; issue.Data[Constants.Runner.InternalTelemetryIssueDataKey] = $"{Constants.Runner.UnsupportedCommand}_{envName}"; - context.AddIssue(issue); + context.AddIssue(issue, ExecutionContextLogOptions.Default); return; } @@ -315,7 +315,7 @@ namespace GitHub.Runner.Worker Message = String.Format(Constants.Runner.UnsupportedCommandMessage, this.Command) }; issue.Data[Constants.Runner.InternalTelemetryIssueDataKey] = Constants.Runner.UnsupportedCommand; - context.AddIssue(issue); + context.AddIssue(issue, ExecutionContextLogOptions.Default); } if (!command.Properties.TryGetValue(SetOutputCommandProperties.Name, out string outputName) || string.IsNullOrEmpty(outputName)) @@ -350,7 +350,7 @@ namespace GitHub.Runner.Worker Message = String.Format(Constants.Runner.UnsupportedCommandMessage, this.Command) }; issue.Data[Constants.Runner.InternalTelemetryIssueDataKey] = Constants.Runner.UnsupportedCommand; - context.AddIssue(issue); + context.AddIssue(issue, ExecutionContextLogOptions.Default); } if (!command.Properties.TryGetValue(SaveStateCommandProperties.Name, out string stateName) || string.IsNullOrEmpty(stateName)) @@ -666,7 +666,7 @@ namespace GitHub.Runner.Worker } } - context.AddIssue(issue); + context.AddIssue(issue, ExecutionContextLogOptions.Default); } public static void ValidateLinesAndColumns(ActionCommand command, IExecutionContext context) diff --git a/src/Runner.Worker/ExecutionContext.cs b/src/Runner.Worker/ExecutionContext.cs index a5df0379f..70b78cc63 100644 --- a/src/Runner.Worker/ExecutionContext.cs +++ b/src/Runner.Worker/ExecutionContext.cs @@ -24,10 +24,16 @@ using Pipelines = GitHub.DistributedTask.Pipelines; namespace GitHub.Runner.Worker { - public class ExecutionContextType + public static class ExecutionContextType { - public static string Job = "Job"; - public static string Task = "Task"; + public const string Job = "Job"; + public const string Task = "Task"; + } + + public record ExecutionContextLogOptions(bool WriteToLog, string LogMessageOverride) + { + public static readonly ExecutionContextLogOptions None = new(false, null); + public static readonly ExecutionContextLogOptions Default = new(true, null); } [ServiceLocator(Default = typeof(ExecutionContext))] @@ -93,7 +99,7 @@ namespace GitHub.Runner.Worker void SetGitHubContext(string name, string value); void SetOutput(string name, string value, out string reference); void SetTimeout(TimeSpan? timeout); - void AddIssue(Issue issue, string message = null); + void AddIssue(Issue issue, ExecutionContextLogOptions logOptions); void Progress(int percentage, string currentOperation = null); void UpdateDetailTimelineRecord(TimelineRecord record); @@ -119,7 +125,7 @@ namespace GitHub.Runner.Worker public sealed class ExecutionContext : RunnerService, IExecutionContext { - private const int _maxIssueCount = 10; + private const int _maxCountPerIssueType = 10; private const int _throttlingDelayReportThreshold = 10 * 1000; // Don't report throttling with less than 10 seconds delay private const int _maxIssueMessageLength = 4096; // Don't send issue with huge message since we can't forward them from actions to check annotation. private const int _maxIssueCountInTelemetry = 3; // Only send the first 3 issues to telemetry @@ -127,8 +133,10 @@ namespace GitHub.Runner.Worker private readonly TimelineRecord _record = new(); private readonly Dictionary _detailRecords = new(); + private readonly List _embeddedIssueCollector; private readonly object _loggerLock = new(); private readonly object _matchersLock = new(); + private readonly ExecutionContext _parentExecutionContext; private event OnMatcherChanged _onMatcherChanged; @@ -136,7 +144,6 @@ namespace GitHub.Runner.Worker private IPagingLogger _logger; private IJobServerQueue _jobServerQueue; - private ExecutionContext _parentExecutionContext; private Guid _mainTimelineId; private Guid _detailTimelineId; @@ -150,6 +157,29 @@ namespace GitHub.Runner.Worker private long _totalThrottlingDelayInMilliseconds = 0; private bool _stepTelemetryPublished = false; + public ExecutionContext() + : this(parent: null, embedded: false) + { + } + + private ExecutionContext(ExecutionContext parent, bool embedded) + { + if (embedded) + { + ArgUtil.NotNull(parent, nameof(parent)); + } + + _parentExecutionContext = parent; + this.IsEmbedded = embedded; + this.StepTelemetry = new ActionsStepTelemetry + { + IsEmbedded = embedded + }; + + //Embedded Execution Contexts pseudo-inherit their parent's embeddedIssueCollector. + _embeddedIssueCollector = embedded ? parent._embeddedIssueCollector : new(); + } + public Guid Id => _record.Id; public Guid EmbeddedId { get; private set; } public string ScopeName { get; private set; } @@ -162,7 +192,7 @@ namespace GitHub.Runner.Worker public Dictionary JobOutputs { get; private set; } public ActionsEnvironmentReference ActionsEnvironment { get; private set; } - public ActionsStepTelemetry StepTelemetry { get; } = new ActionsStepTelemetry(); + public ActionsStepTelemetry StepTelemetry { get; private init; } public DictionaryContextData ExpressionValues { get; } = new DictionaryContextData(); public IList ExpressionFunctions { get; } = new List(); @@ -187,7 +217,7 @@ namespace GitHub.Runner.Worker // An embedded execution context shares the same record ID, record name, and logger // as its enclosing execution context. - public bool IsEmbedded { get; private set; } + public bool IsEmbedded { get; private init; } public TaskResult? Result { @@ -322,7 +352,7 @@ namespace GitHub.Runner.Worker { Trace.Entering(); - var child = new ExecutionContext(); + var child = new ExecutionContext(this, isEmbedded); child.Initialize(HostContext); child.Global = Global; child.ScopeName = scopeName; @@ -347,7 +377,6 @@ namespace GitHub.Runner.Worker child.ExpressionFunctions.Add(item); } child._cancellationTokenSource = cancellationTokenSource ?? new CancellationTokenSource(); - child._parentExecutionContext = this; child.EchoOnActionCommand = EchoOnActionCommand; if (recordOrder != null) @@ -368,11 +397,9 @@ namespace GitHub.Runner.Worker child._logger.Setup(_mainTimelineId, recordId); } - child.IsEmbedded = isEmbedded; child.StepTelemetry.StepId = recordId; child.StepTelemetry.Stage = stage.ToString(); - child.StepTelemetry.IsEmbedded = isEmbedded; - child.StepTelemetry.StepContextName = child.GetFullyQualifiedContextName(); ; + child.StepTelemetry.StepContextName = child.GetFullyQualifiedContextName(); return child; } @@ -414,13 +441,24 @@ namespace GitHub.Runner.Worker this.Warning($"The job has experienced {TimeSpan.FromMilliseconds(_totalThrottlingDelayInMilliseconds).TotalSeconds} seconds total delay caused by server throttling."); } + DateTime now = DateTime.UtcNow; _record.CurrentOperation = currentOperation ?? _record.CurrentOperation; _record.ResultCode = resultCode ?? _record.ResultCode; - _record.FinishTime = DateTime.UtcNow; + _record.FinishTime = now; _record.PercentComplete = 100; _record.Result = _record.Result ?? TaskResult.Succeeded; _record.State = TimelineRecordState.Completed; + // Before our main timeline's final QueueTimelineRecordUpdate, + // inject any issues collected by embedded ExecutionContexts. + if (!this.IsEmbedded) + { + foreach (var issue in _embeddedIssueCollector) + { + AddIssue(issue, ExecutionContextLogOptions.None); + } + } + _jobServerQueue.QueueTimelineRecordUpdate(_mainTimelineId, _record); // complete all detail timeline records. @@ -428,7 +466,7 @@ namespace GitHub.Runner.Worker { foreach (var record in _detailRecords) { - record.Value.FinishTime = record.Value.FinishTime ?? DateTime.UtcNow; + record.Value.FinishTime = record.Value.FinishTime ?? now; record.Value.PercentComplete = record.Value.PercentComplete ?? 100; record.Value.Result = record.Value.Result ?? TaskResult.Succeeded; record.Value.State = TimelineRecordState.Completed; @@ -572,14 +610,10 @@ namespace GitHub.Runner.Worker } // This is not thread safe, the caller need to take lock before calling issue() - public void AddIssue(Issue issue, string logMessage = null) + public void AddIssue(Issue issue, ExecutionContextLogOptions logOptions) { ArgUtil.NotNull(issue, nameof(issue)); - - if (string.IsNullOrEmpty(logMessage)) - { - logMessage = issue.Message; - } + ArgUtil.NotNull(logOptions, nameof(logOptions)); issue.Message = HostContext.SecretMasker.MaskSecrets(issue.Message); if (issue.Message.Length > _maxIssueMessageLength) @@ -594,53 +628,64 @@ namespace GitHub.Runner.Worker issue.Data["stepNumber"] = _record.Order.ToString(); } - if (issue.Type == IssueType.Error) + string wellKnownTag = null; + Int32 previousCountForIssueType = 0; + Action incrementIssueTypeCount = NoOp; + switch (issue.Type) { - if (!string.IsNullOrEmpty(logMessage)) - { - long logLineNumber = Write(WellKnownTags.Error, logMessage); - issue.Data["logFileLineNumber"] = logLineNumber.ToString(); - } + case IssueType.Error: + wellKnownTag = WellKnownTags.Error; + previousCountForIssueType = _record.ErrorCount; + incrementIssueTypeCount = () => { _record.ErrorCount++; }; + break; + case IssueType.Warning: + wellKnownTag = WellKnownTags.Warning; + previousCountForIssueType = _record.WarningCount; + incrementIssueTypeCount = () => { _record.WarningCount++; }; + break; + case IssueType.Notice: + wellKnownTag = WellKnownTags.Notice; + previousCountForIssueType = _record.NoticeCount; + incrementIssueTypeCount = () => { _record.NoticeCount++; }; + break; + } - if (_record.ErrorCount < _maxIssueCount) + if (!string.IsNullOrEmpty(wellKnownTag)) + { + if (!this.IsEmbedded && previousCountForIssueType < _maxCountPerIssueType) { + incrementIssueTypeCount(); _record.Issues.Add(issue); } - _record.ErrorCount++; + if (logOptions.WriteToLog) + { + string logMessage = issue.Message; + if (!string.IsNullOrEmpty(logOptions.LogMessageOverride)) + { + logMessage = logOptions.LogMessageOverride; + } + + if (!string.IsNullOrEmpty(logMessage)) + { + // Note that ::Write() has its own secret-masking logic. + long logLineNumber = Write(wellKnownTag, logMessage); + issue.Data["logFileLineNumber"] = logLineNumber.ToString(); + } + } } - else if (issue.Type == IssueType.Warning) + + // Embedded ExecutionContexts (a.k.a. Composite actions) should never upload a timeline record to the server. + // Instead, we store processed issues on a shared (psuedo-inherited) list (belonging to the closest + // non-embedded ancestor ExecutionContext) so that they can be processed when that ancestor completes. + if (this.IsEmbedded) { - if (!string.IsNullOrEmpty(logMessage)) - { - long logLineNumber = Write(WellKnownTags.Warning, logMessage); - issue.Data["logFileLineNumber"] = logLineNumber.ToString(); - } - - if (_record.WarningCount < _maxIssueCount) - { - _record.Issues.Add(issue); - } - - _record.WarningCount++; + _embeddedIssueCollector.Add(issue); } - else if (issue.Type == IssueType.Notice) + else { - if (!string.IsNullOrEmpty(logMessage)) - { - long logLineNumber = Write(WellKnownTags.Notice, logMessage); - issue.Data["logFileLineNumber"] = logLineNumber.ToString(); - } - - if (_record.NoticeCount < _maxIssueCount) - { - _record.Issues.Add(issue); - } - - _record.NoticeCount++; + _jobServerQueue.QueueTimelineRecordUpdate(_mainTimelineId, _record); } - - _jobServerQueue.QueueTimelineRecordUpdate(_mainTimelineId, _record); } public void UpdateDetailTimelineRecord(TimelineRecord record) @@ -1014,8 +1059,7 @@ namespace GitHub.Runner.Worker StepTelemetry.FinishTime = _record.FinishTime; } - if (!IsEmbedded && - _record.Issues.Count > 0) + if (!IsEmbedded) { foreach (var issue in _record.Issues) { @@ -1181,6 +1225,11 @@ namespace GitHub.Runner.Worker UpdateGlobalStepsContext(); } + + private static void NoOp() + { + } + } // The Error/Warning/etc methods are created as extension methods to simplify unit testing. @@ -1205,19 +1254,22 @@ namespace GitHub.Runner.Worker // Do not add a format string overload. See comment on ExecutionContext.Write(). public static void Error(this IExecutionContext context, string message) { - context.AddIssue(new Issue() { Type = IssueType.Error, Message = message }); + var issue = new Issue() { Type = IssueType.Error, Message = message }; + context.AddIssue(issue, ExecutionContextLogOptions.Default); } // Do not add a format string overload. See comment on ExecutionContext.Write(). public static void InfrastructureError(this IExecutionContext context, string message) { - context.AddIssue(new Issue() { Type = IssueType.Error, Message = message, IsInfrastructureIssue = true }); + var issue = new Issue() { Type = IssueType.Error, Message = message, IsInfrastructureIssue = true }; + context.AddIssue(issue, ExecutionContextLogOptions.Default); } // Do not add a format string overload. See comment on ExecutionContext.Write(). public static void Warning(this IExecutionContext context, string message) { - context.AddIssue(new Issue() { Type = IssueType.Warning, Message = message }); + var issue = new Issue() { Type = IssueType.Warning, Message = message }; + context.AddIssue(issue, ExecutionContextLogOptions.Default); } // Do not add a format string overload. See comment on ExecutionContext.Write(). diff --git a/src/Runner.Worker/Handlers/CompositeActionHandler.cs b/src/Runner.Worker/Handlers/CompositeActionHandler.cs index 4cc54af41..7728ad886 100644 --- a/src/Runner.Worker/Handlers/CompositeActionHandler.cs +++ b/src/Runner.Worker/Handlers/CompositeActionHandler.cs @@ -294,7 +294,7 @@ namespace GitHub.Runner.Worker.Handlers // Evaluation error Trace.Info("Caught exception from expression for embedded step.env"); step.ExecutionContext.Error(ex); - step.ExecutionContext.Complete(TaskResult.Failed); + SetStepConclusion(step, TaskResult.Failed); } // Register Callback diff --git a/src/Runner.Worker/Handlers/OutputManager.cs b/src/Runner.Worker/Handlers/OutputManager.cs index 8b97c867d..5dd94059b 100644 --- a/src/Runner.Worker/Handlers/OutputManager.cs +++ b/src/Runner.Worker/Handlers/OutputManager.cs @@ -143,7 +143,8 @@ namespace GitHub.Runner.Worker.Handlers if (issue != null) { // Log issue - _executionContext.AddIssue(issue, stripped); + var logOptions = new ExecutionContextLogOptions(true, stripped); + _executionContext.AddIssue(issue, logOptions); return; } diff --git a/src/Runner.Worker/JobExtension.cs b/src/Runner.Worker/JobExtension.cs index 580c9999d..42e6fea81 100644 --- a/src/Runner.Worker/JobExtension.cs +++ b/src/Runner.Worker/JobExtension.cs @@ -683,7 +683,7 @@ namespace GitHub.Runner.Worker { var issue = new Issue() { Type = IssueType.Warning, Message = $"You are running out of disk space. The runner will stop working when the machine runs out of disk space. Free space left: {freeSpaceInMB} MB" }; issue.Data[Constants.Runner.InternalTelemetryIssueDataKey] = Constants.Runner.LowDiskSpace; - context.AddIssue(issue); + context.AddIssue(issue, ExecutionContextLogOptions.Default); return; } diff --git a/src/Runner.Worker/JobRunner.cs b/src/Runner.Worker/JobRunner.cs index e2803dc1c..737ad6d85 100644 --- a/src/Runner.Worker/JobRunner.cs +++ b/src/Runner.Worker/JobRunner.cs @@ -120,7 +120,8 @@ namespace GitHub.Runner.Worker default: throw new ArgumentException(HostContext.RunnerShutdownReason.ToString(), nameof(HostContext.RunnerShutdownReason)); } - jobContext.AddIssue(new Issue() { Type = IssueType.Error, Message = errorMessage }); + var issue = new Issue() { Type = IssueType.Error, Message = errorMessage }; + jobContext.AddIssue(issue, ExecutionContextLogOptions.Default); }); // Validate directory permissions. diff --git a/src/Sdk/DTWebApi/WebApi/TimelineRecord.cs b/src/Sdk/DTWebApi/WebApi/TimelineRecord.cs index 51317d171..4d4157223 100644 --- a/src/Sdk/DTWebApi/WebApi/TimelineRecord.cs +++ b/src/Sdk/DTWebApi/WebApi/TimelineRecord.cs @@ -1,8 +1,7 @@ -using System; +using System; using System.Collections.Generic; using System.Linq; using System.Runtime.Serialization; -using GitHub.Services.Common; namespace GitHub.DistributedTask.WebApi { @@ -10,69 +9,78 @@ namespace GitHub.DistributedTask.WebApi public sealed class TimelineRecord { public TimelineRecord() + : this(null) { - this.Attempt = 1; } private TimelineRecord(TimelineRecord recordToBeCloned) { - this.Attempt = recordToBeCloned.Attempt; - this.ChangeId = recordToBeCloned.ChangeId; - this.CurrentOperation = recordToBeCloned.CurrentOperation; - this.FinishTime = recordToBeCloned.FinishTime; - this.Id = recordToBeCloned.Id; - this.Identifier = recordToBeCloned.Identifier; - this.LastModified = recordToBeCloned.LastModified; - this.Location = recordToBeCloned.Location; - this.Name = recordToBeCloned.Name; - this.Order = recordToBeCloned.Order; - this.ParentId = recordToBeCloned.ParentId; - this.PercentComplete = recordToBeCloned.PercentComplete; - this.RecordType = recordToBeCloned.RecordType; - this.Result = recordToBeCloned.Result; - this.ResultCode = recordToBeCloned.ResultCode; - this.StartTime = recordToBeCloned.StartTime; - this.State = recordToBeCloned.State; - this.TimelineId = recordToBeCloned.TimelineId; - this.WorkerName = recordToBeCloned.WorkerName; - this.RefName = recordToBeCloned.RefName; - this.ErrorCount = recordToBeCloned.ErrorCount; - this.WarningCount = recordToBeCloned.WarningCount; - this.NoticeCount = recordToBeCloned.NoticeCount; - this.AgentPlatform = recordToBeCloned.AgentPlatform; + this.EnsureInitialized(); - if (recordToBeCloned.Log != null) + if (recordToBeCloned != null) { - this.Log = new TaskLogReference + this.Attempt = recordToBeCloned.Attempt; + this.ChangeId = recordToBeCloned.ChangeId; + this.CurrentOperation = recordToBeCloned.CurrentOperation; + this.FinishTime = recordToBeCloned.FinishTime; + this.Id = recordToBeCloned.Id; + this.Identifier = recordToBeCloned.Identifier; + this.LastModified = recordToBeCloned.LastModified; + this.Location = recordToBeCloned.Location; + this.Name = recordToBeCloned.Name; + this.Order = recordToBeCloned.Order; + this.ParentId = recordToBeCloned.ParentId; + this.PercentComplete = recordToBeCloned.PercentComplete; + this.RecordType = recordToBeCloned.RecordType; + this.Result = recordToBeCloned.Result; + this.ResultCode = recordToBeCloned.ResultCode; + this.StartTime = recordToBeCloned.StartTime; + this.State = recordToBeCloned.State; + this.TimelineId = recordToBeCloned.TimelineId; + this.WorkerName = recordToBeCloned.WorkerName; + this.RefName = recordToBeCloned.RefName; + this.ErrorCount = recordToBeCloned.ErrorCount; + this.WarningCount = recordToBeCloned.WarningCount; + this.NoticeCount = recordToBeCloned.NoticeCount; + this.AgentPlatform = recordToBeCloned.AgentPlatform; + + if (recordToBeCloned.Log != null) { - Id = recordToBeCloned.Log.Id, - Location = recordToBeCloned.Log.Location, - }; - } + this.Log = new TaskLogReference + { + Id = recordToBeCloned.Log.Id, + Location = recordToBeCloned.Log.Location, + }; + } - if (recordToBeCloned.Details != null) - { - this.Details = new TimelineReference + if (recordToBeCloned.Details != null) { - ChangeId = recordToBeCloned.Details.ChangeId, - Id = recordToBeCloned.Details.Id, - Location = recordToBeCloned.Details.Location, - }; - } + this.Details = new TimelineReference + { + ChangeId = recordToBeCloned.Details.ChangeId, + Id = recordToBeCloned.Details.Id, + Location = recordToBeCloned.Details.Location, + }; + } - if (recordToBeCloned.m_issues?.Count> 0) - { - this.Issues.AddRange(recordToBeCloned.Issues.Select(i => i.Clone())); - } + if (recordToBeCloned.m_issues?.Count > 0) + { + this.Issues.AddRange(recordToBeCloned.Issues.Select(i => i.Clone())); + } - if (recordToBeCloned.m_previousAttempts?.Count > 0) - { - this.PreviousAttempts.AddRange(recordToBeCloned.PreviousAttempts); - } + if (recordToBeCloned.m_previousAttempts?.Count > 0) + { + this.m_previousAttempts.AddRange(recordToBeCloned.m_previousAttempts); + } - if (recordToBeCloned.m_variables?.Count > 0) - { - this.m_variables = recordToBeCloned.Variables.ToDictionary(k => k.Key, v => v.Value.Clone()); + if (recordToBeCloned.m_variables?.Count > 0) + { + // Don't pave over the case-insensitive Dictionary we initialized above. + foreach (var kvp in recordToBeCloned.m_variables) + { + m_variables[kvp.Key] = kvp.Value.Clone(); + } + } } } @@ -98,14 +106,14 @@ namespace GitHub.DistributedTask.WebApi } [DataMember(Name = "Type", Order = 3)] - public String RecordType + public string RecordType { get; set; } [DataMember(Order = 4)] - public String Name + public string Name { get; set; @@ -126,7 +134,7 @@ namespace GitHub.DistributedTask.WebApi } [DataMember(Order = 7)] - public String CurrentOperation + public string CurrentOperation { get; set; @@ -154,7 +162,7 @@ namespace GitHub.DistributedTask.WebApi } [DataMember(Order = 11)] - public String ResultCode + public string ResultCode { get; set; @@ -175,7 +183,7 @@ namespace GitHub.DistributedTask.WebApi } [DataMember(Order = 14)] - public String WorkerName + public string WorkerName { get; set; @@ -189,7 +197,7 @@ namespace GitHub.DistributedTask.WebApi } [DataMember(Order = 16, EmitDefaultValue = false)] - public String RefName + public string RefName { get; set; @@ -209,35 +217,46 @@ namespace GitHub.DistributedTask.WebApi set; } - [DataMember(Order = 40)] - public Int32? ErrorCount + public Int32 ErrorCount { - get; - set; + get + { + return m_errorCount.GetValueOrDefault(0); + } + set + { + m_errorCount = value; + } } - [DataMember(Order = 50)] - public Int32? WarningCount + public Int32 WarningCount { - get; - set; + get + { + return m_warningCount.GetValueOrDefault(0); + } + set + { + m_warningCount = value; + } } - [DataMember(Order = 55)] - public Int32? NoticeCount + public Int32 NoticeCount { - get; - set; + get + { + return m_noticeCount.GetValueOrDefault(0); + } + set + { + m_noticeCount = value; + } } public List Issues { get { - if (m_issues == null) - { - m_issues = new List(); - } return m_issues; } } @@ -257,7 +276,7 @@ namespace GitHub.DistributedTask.WebApi } [DataMember(Order = 131)] - public String Identifier + public string Identifier { get; set; @@ -274,22 +293,14 @@ namespace GitHub.DistributedTask.WebApi { get { - if (m_previousAttempts == null) - { - m_previousAttempts = new List(); - } return m_previousAttempts; } } - public IDictionary Variables + public IDictionary Variables { get { - if (m_variables == null) - { - m_variables = new Dictionary(StringComparer.OrdinalIgnoreCase); - } return m_variables; } } @@ -299,13 +310,53 @@ namespace GitHub.DistributedTask.WebApi return new TimelineRecord(this); } - [DataMember(Name = "Issues", EmitDefaultValue = false, Order = 60)] + [OnDeserialized] + private void OnDeserialized(StreamingContext context) + { + this.EnsureInitialized(); + } + + + /// + /// DataContractSerializer bypasses all constructor logic and inline initialization! + /// This method takes the place of a workhorse constructor for baseline initialization. + /// The expectation is for this logic to be accessible to constructors and also to the OnDeserialized helper. + /// + private void EnsureInitialized() + { + // Note that ?? is a short-circuiting operator. (??= would be preferable, but it's not supported in the .NET Framework version currently used by actions/runner.) + + // De-nullify the following historically-nullable ints. + // (After several weeks in production, it may be possible to eliminate these nullable backing fields.) + m_errorCount = m_errorCount ?? 0; + m_warningCount = m_warningCount ?? 0; + m_noticeCount = m_noticeCount ?? 0; + + m_issues = m_issues ?? new List(); + m_previousAttempts = m_previousAttempts ?? new List(); + this.Attempt = Math.Max(this.Attempt, 1); + + // Ensure whatever content may have been deserialized for m_variables is backed by a case-insensitive Dictionary. + var empty = Enumerable.Empty>(); + m_variables = new Dictionary(m_variables ?? empty, StringComparer.OrdinalIgnoreCase); + } + + [DataMember(Name = nameof(ErrorCount), Order = 40)] + private Int32? m_errorCount; + + [DataMember(Name = nameof(WarningCount), Order = 50)] + private Int32? m_warningCount; + + [DataMember(Name = nameof(NoticeCount), Order = 55)] + private Int32? m_noticeCount; + + [DataMember(Name = nameof(Issues), EmitDefaultValue = false, Order = 60)] private List m_issues; - [DataMember(Name = "Variables", EmitDefaultValue = false, Order = 80)] - private Dictionary m_variables; + [DataMember(Name = nameof(Variables), EmitDefaultValue = false, Order = 80)] + private Dictionary m_variables; - [DataMember(Name = "PreviousAttempts", EmitDefaultValue = false, Order = 120)] + [DataMember(Name = nameof(PreviousAttempts), EmitDefaultValue = false, Order = 120)] private List m_previousAttempts; } } diff --git a/src/Test/L0/DistributedTask/WebApi/TimelineRecordL0.cs b/src/Test/L0/DistributedTask/WebApi/TimelineRecordL0.cs new file mode 100644 index 000000000..7df9cf392 --- /dev/null +++ b/src/Test/L0/DistributedTask/WebApi/TimelineRecordL0.cs @@ -0,0 +1,270 @@ +#nullable enable + +using System; +using System.IO; +using System.Collections.Generic; +using System.Linq; +using System.Runtime.Serialization.Json; +using GitHub.DistributedTask.WebApi; +using Xunit; +using System.Text; + +namespace GitHub.Runner.Common.Tests.DistributedTask +{ + public sealed class TimelineRecordL0 + { + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "DistributedTask")] + public void VerifyTimelineRecord_Defaults() + { + var tr = new TimelineRecord(); + + Assert.Equal(0, tr.ErrorCount); + Assert.Equal(0, tr.WarningCount); + Assert.Equal(0, tr.NoticeCount); + Assert.Equal(1, tr.Attempt); + Assert.NotNull(tr.Issues); + Assert.NotNull(tr.PreviousAttempts); + Assert.NotNull(tr.Variables); + } + + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "DistributedTask")] + public void VerifyTimelineRecord_Clone() + { + var original = new TimelineRecord(); + original.ErrorCount = 100; + original.WarningCount = 200; + original.NoticeCount = 300; + original.Attempt = 3; + + // The Variables dictionary should be a case-insensitive dictionary. + original.Variables["xxx"] = new VariableValue("first", false); + original.Variables["XXX"] = new VariableValue("second", false); + + Assert.Equal(1, original.Variables.Count); + Assert.Equal("second", original.Variables.Values.First().Value); + Assert.Equal("second", original.Variables["xXx"].Value); + + var clone = original.Clone(); + + Assert.NotSame(original, clone); + Assert.NotSame(original.Variables, clone.Variables); + Assert.Equal(100, clone.ErrorCount); + Assert.Equal(200, clone.WarningCount); + Assert.Equal(300, clone.NoticeCount); + Assert.Equal(3, clone.Attempt); + + // Now, mutate the original post-clone. + original.ErrorCount++; + original.WarningCount += 10; + original.NoticeCount *= 3; + original.Attempt--; + original.Variables["a"] = new VariableValue("1", false); + + // Verify that the clone was unaffected by the changes to the original. + Assert.Equal(100, clone.ErrorCount); + Assert.Equal(200, clone.WarningCount); + Assert.Equal(300, clone.NoticeCount); + Assert.Equal(3, clone.Attempt); + Assert.Equal(1, clone.Variables.Count); + Assert.Equal("second", clone.Variables.Values.First().Value); + + // Verify that the clone's Variables dictionary is also case-sensitive. + clone.Variables["yyy"] = new VariableValue("third", false); + clone.Variables["YYY"] = new VariableValue("fourth", false); + + Assert.Equal(2, clone.Variables.Count); + Assert.Equal("second", clone.Variables["xXx"].Value); + Assert.Equal("fourth", clone.Variables["yYy"].Value); + } + + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "DistributedTask")] + public void VerifyTimelineRecord_DeserializationEdgeCase_NonNullCollections() + { + var jsonSamples = LoadJsonSamples(JsonSamplesFilePath); + + // Verify that missing JSON fields don't result in null values for collection properties. + var tr = Deserialize(jsonSamples["minimal"]); + Assert.NotNull(tr); + Assert.Equal("minimal", tr!.Name); + Assert.NotNull(tr.Issues); + Assert.NotNull(tr.PreviousAttempts); + Assert.NotNull(tr.Variables); + + // Verify that explicitly-null JSON fields don't result in null values for collection properties. + // (Our deserialization logic should fix these up and instantiate an empty collection.) + tr = Deserialize(jsonSamples["explicit-null-collections"]); + Assert.NotNull(tr); + Assert.Equal("explicit-null-collections", tr!.Name); + Assert.NotNull(tr.Issues); + Assert.NotNull(tr.PreviousAttempts); + Assert.NotNull(tr.Variables); + } + + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "DistributedTask")] + public void VerifyTimelineRecord_DeserializationEdgeCase_AttemptCannotBeLessThan1() + { + var jsonSamples = LoadJsonSamples(JsonSamplesFilePath); + + // Verify that 1 is the effective floor for TimelineRecord::Attempt. + var tr = Deserialize(jsonSamples["minimal"]); + Assert.NotNull(tr); + Assert.Equal("minimal", tr!.Name); + Assert.Equal(1, tr.Attempt); + + tr = Deserialize(jsonSamples["invalid-attempt-value"]); + Assert.NotNull(tr); + Assert.Equal("invalid-attempt-value", tr!.Name); + Assert.Equal(1, tr.Attempt); + + tr = Deserialize(jsonSamples["zero-attempt-value"]); + Assert.NotNull(tr); + Assert.Equal("zero-attempt-value", tr!.Name); + Assert.Equal(1, tr.Attempt); + } + + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "DistributedTask")] + public void VerifyTimelineRecord_DeserializationEdgeCase_HandleLegacyNullsGracefully() + { + var jsonSamples = LoadJsonSamples(JsonSamplesFilePath); + + // Verify that nulls for ErrorCount, WarningCount, and NoticeCount are interpreted as 0. + var tr = Deserialize(jsonSamples["legacy-nulls"]); + Assert.NotNull(tr); + Assert.Equal("legacy-nulls", tr!.Name); + Assert.Equal(0, tr.ErrorCount); + Assert.Equal(0, tr.WarningCount); + Assert.Equal(0, tr.NoticeCount); + } + + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "DistributedTask")] + public void VerifyTimelineRecord_DeserializationEdgeCase_HandleMissingCountsGracefully() + { + var jsonSamples = LoadJsonSamples(JsonSamplesFilePath); + + // Verify that nulls for ErrorCount, WarningCount, and NoticeCount are interpreted as 0. + var tr = Deserialize(jsonSamples["missing-counts"]); + Assert.NotNull(tr); + Assert.Equal("missing-counts", tr!.Name); + Assert.Equal(0, tr.ErrorCount); + Assert.Equal(0, tr.WarningCount); + Assert.Equal(0, tr.NoticeCount); + } + + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "DistributedTask")] + public void VerifyTimelineRecord_DeserializationEdgeCase_NonZeroCounts() + { + var jsonSamples = LoadJsonSamples(JsonSamplesFilePath); + + // Verify that nulls for ErrorCount, WarningCount, and NoticeCount are interpreted as 0. + var tr = Deserialize(jsonSamples["non-zero-counts"]); + Assert.NotNull(tr); + Assert.Equal("non-zero-counts", tr!.Name); + Assert.Equal(10, tr.ErrorCount); + Assert.Equal(20, tr.WarningCount); + Assert.Equal(30, tr.NoticeCount); + } + + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "DistributedTask")] + public void VerifyTimelineRecord_Deserialization_LeanTimelineRecord() + { + var jsonSamples = LoadJsonSamples(JsonSamplesFilePath); + + // Verify that a lean TimelineRecord can be deserialized. + var tr = Deserialize(jsonSamples["lean"]); + Assert.NotNull(tr); + Assert.Equal("lean", tr!.Name); + Assert.Equal(4, tr.Attempt); + Assert.Equal(1, tr.Issues.Count); + Assert.Equal(3, tr.Variables.Count); + Assert.Equal(3, tr.PreviousAttempts.Count); + } + + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "DistributedTask")] + public void VerifyTimelineRecord_Deserialization_VariablesDictionaryIsCaseInsensitive() + { + var jsonSamples = LoadJsonSamples(JsonSamplesFilePath); + + var tr = Deserialize(jsonSamples["lean"]); + Assert.NotNull(tr); + Assert.Equal("lean", tr!.Name); + Assert.Equal(3, tr.Variables.Count); + + // Verify that the Variables Dictionary is case-insensitive. + tr.Variables["X"] = new VariableValue("overwritten", false); + Assert.Equal(3, tr.Variables.Count); + + tr.Variables["new"] = new VariableValue("new.1", false); + Assert.Equal(4, tr.Variables.Count); + + tr.Variables["NEW"] = new VariableValue("new.2", false); + Assert.Equal(4, tr.Variables.Count); + } + + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "DistributedTask")] + public void VerifyTimelineRecord_DeserializationEdgeCase_DuplicateVariableKeysThrowsException() + { + var jsonSamples = LoadJsonSamples(JsonSamplesFilePath); + + // We could be more forgiving in this case if we discover that it's not uncommon in Production for serialized TimelineRecords to: + // 1) get incorrectly instantiated with a case-sensitive Variables dictionary (in older versions, this was possible via TimelineRecord::Clone) + // 2) end up with case variations of the same key + // 3) make another serialization/deserialization round trip. + // + // If we wanted to grant clemency to such incorrectly-serialized TimelineRecords, + // the fix to TimelineRecord::EnsureInitialized would look something like the following: + // + // var seedVariables = m_variables ?? Enumerable.Empty>(); + // m_variables = new Dictionary(seedVariables.Count(), StringComparer.OrdinalIgnoreCase); + // foreach (var kvp in seedVariables) + // { + // m_variables[kvp.Key] = kvp.Value; + // } + Assert.Throws(() => Deserialize(jsonSamples["duplicate-variable-keys"])); + } + + + private static Dictionary LoadJsonSamples(string path) + { + // Embedding independent JSON samples within YML works well because JSON generally doesn't need to be escaped or otherwise mangled. + var yamlDeserializer = new YamlDotNet.Serialization.Deserializer(); + using var stream = new StreamReader(path); + return yamlDeserializer.Deserialize>(stream); + } + + private static TimelineRecord? Deserialize(string rawJson) + { + using var stream = new MemoryStream(Encoding.UTF8.GetBytes(rawJson ?? string.Empty)); + return m_jsonSerializer.ReadObject(stream) as TimelineRecord; + } + + private static string JsonSamplesFilePath + { + get + { + return Path.Combine(TestUtil.GetTestDataPath(), "timelinerecord_json_samples.yml"); + } + } + + private static readonly DataContractJsonSerializer m_jsonSerializer = new(typeof(TimelineRecord)); + } +} diff --git a/src/Test/L0/Worker/ActionCommandManagerL0.cs b/src/Test/L0/Worker/ActionCommandManagerL0.cs index cef826fd9..78a5ebd69 100644 --- a/src/Test/L0/Worker/ActionCommandManagerL0.cs +++ b/src/Test/L0/Worker/ActionCommandManagerL0.cs @@ -1,4 +1,4 @@ -using System; +using System; using System.Collections.Generic; using System.IO; using System.Runtime.CompilerServices; @@ -32,10 +32,10 @@ namespace GitHub.Runner.Common.Tests.Worker hc.GetTrace().Info($"{tag} {line}"); return 1; }); - _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) - .Callback((Issue issue, string message) => + _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) + .Callback((Issue issue, ExecutionContextLogOptions logOptions) => { - hc.GetTrace().Info($"{issue.Type} {issue.Message} {message ?? string.Empty}"); + hc.GetTrace().Info($"{issue.Type} {issue.Message} {logOptions.LogMessageOverride ?? string.Empty}"); }); _commandManager.EnablePluginInternalCommand(); @@ -59,10 +59,10 @@ namespace GitHub.Runner.Common.Tests.Worker hc.GetTrace().Info($"{tag} {line}"); return 1; }); - _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) - .Callback((Issue issue, string message) => + _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) + .Callback((Issue issue, ExecutionContextLogOptions logOptions) => { - hc.GetTrace().Info($"{issue.Type} {issue.Message} {message ?? string.Empty}"); + hc.GetTrace().Info($"{issue.Type} {issue.Message} {logOptions.LogMessageOverride ?? string.Empty}"); }); _commandManager.EnablePluginInternalCommand(); @@ -92,10 +92,10 @@ namespace GitHub.Runner.Common.Tests.Worker return 1; }); - _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) - .Callback((Issue issue, string message) => + _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) + .Callback((Issue issue, ExecutionContextLogOptions logOptions) => { - hc.GetTrace().Info($"{issue.Type} {issue.Message} {message ?? string.Empty}"); + hc.GetTrace().Info($"{issue.Type} {issue.Message} {logOptions.LogMessageOverride ?? string.Empty}"); }); _ec.Object.Global.EnvironmentVariables = new Dictionary(); diff --git a/src/Test/L0/Worker/ActionManagerL0.cs b/src/Test/L0/Worker/ActionManagerL0.cs index 7a1a3d7a3..6052a848b 100644 --- a/src/Test/L0/Worker/ActionManagerL0.cs +++ b/src/Test/L0/Worker/ActionManagerL0.cs @@ -2148,7 +2148,7 @@ runs: _ec.Object.Global.FileTable = new List(); _ec.Object.Global.Plan = new TaskOrchestrationPlanReference(); _ec.Setup(x => x.Write(It.IsAny(), It.IsAny())).Callback((string tag, string message) => { _hc.GetTrace().Info($"[{tag}]{message}"); }); - _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())).Callback((Issue issue, string message) => { _hc.GetTrace().Info($"[{issue.Type}]{issue.Message ?? message}"); }); + _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())).Callback((Issue issue, ExecutionContextLogOptions logOptions) => { _hc.GetTrace().Info($"[{issue.Type}]{logOptions.LogMessageOverride ?? issue.Message}"); }); _ec.Setup(x => x.GetGitHubContext("workspace")).Returns(Path.Combine(_workFolder, "actions", "actions")); _dockerManager = new Mock(); diff --git a/src/Test/L0/Worker/ActionManifestManagerL0.cs b/src/Test/L0/Worker/ActionManifestManagerL0.cs index b6e3f855b..75010748b 100644 --- a/src/Test/L0/Worker/ActionManifestManagerL0.cs +++ b/src/Test/L0/Worker/ActionManifestManagerL0.cs @@ -670,7 +670,7 @@ namespace GitHub.Runner.Common.Tests.Worker { Teardown(); } - } + } [Fact] [Trait("Level", "L0")] @@ -715,7 +715,7 @@ namespace GitHub.Runner.Common.Tests.Worker //Assert var err = Assert.Throws(() => actionManifest.Load(_ec.Object, action_path)); Assert.Contains($"Fail to load {action_path}", err.Message); - _ec.Verify(x => x.AddIssue(It.Is(s => s.Message.Contains("Missing 'using' value. 'using' requires 'composite', 'docker', 'node12' or 'node16'.")), It.IsAny()), Times.Once); + _ec.Verify(x => x.AddIssue(It.Is(s => s.Message.Contains("Missing 'using' value. 'using' requires 'composite', 'docker', 'node12' or 'node16'.")), It.IsAny()), Times.Once); } finally { @@ -860,7 +860,7 @@ namespace GitHub.Runner.Common.Tests.Worker _ec.Setup(x => x.ExpressionValues).Returns(new DictionaryContextData()); _ec.Setup(x => x.ExpressionFunctions).Returns(new List()); _ec.Setup(x => x.Write(It.IsAny(), It.IsAny())).Callback((string tag, string message) => { _hc.GetTrace().Info($"{tag}{message}"); }); - _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())).Callback((Issue issue, string message) => { _hc.GetTrace().Info($"[{issue.Type}]{issue.Message ?? message}"); }); + _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())).Callback((Issue issue, ExecutionContextLogOptions logOptions) => { _hc.GetTrace().Info($"[{issue.Type}]{logOptions.LogMessageOverride ?? issue.Message}"); }); } private void Teardown() diff --git a/src/Test/L0/Worker/ActionRunnerL0.cs b/src/Test/L0/Worker/ActionRunnerL0.cs index 586e9dad2..4942f568c 100644 --- a/src/Test/L0/Worker/ActionRunnerL0.cs +++ b/src/Test/L0/Worker/ActionRunnerL0.cs @@ -1,4 +1,4 @@ -using GitHub.DistributedTask.Expressions2; +using GitHub.DistributedTask.Expressions2; using GitHub.DistributedTask.ObjectTemplating.Tokens; using GitHub.DistributedTask.Pipelines; using GitHub.DistributedTask.Pipelines.ContextData; @@ -366,7 +366,7 @@ namespace GitHub.Runner.Common.Tests.Worker Assert.Equal("invalid1", finialInputs["invalid1"]); Assert.Equal("invalid2", finialInputs["invalid2"]); - _ec.Verify(x => x.AddIssue(It.Is(s => s.Message.Contains("Unexpected input(s) 'invalid1', 'invalid2'")), It.IsAny()), Times.Once); + _ec.Verify(x => x.AddIssue(It.Is(s => s.Message.Contains("Unexpected input(s) 'invalid1', 'invalid2'")), It.IsAny()), Times.Once); } [Fact] @@ -485,7 +485,7 @@ namespace GitHub.Runner.Common.Tests.Worker _ec.Setup(x => x.CancellationToken).Returns(_ecTokenSource.Token); _ec.Object.Global.Variables = new Variables(_hc, new Dictionary()); _ec.Setup(x => x.Write(It.IsAny(), It.IsAny())).Callback((string tag, string message) => { _hc.GetTrace().Info($"[{tag}]{message}"); }); - _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())).Callback((Issue issue, string message) => { _hc.GetTrace().Info($"[{issue.Type}]{issue.Message ?? message}"); }); + _ec.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())).Callback((Issue issue, ExecutionContextLogOptions logOptions) => { _hc.GetTrace().Info($"[{issue.Type}]{logOptions.LogMessageOverride ?? issue.Message}"); }); _hc.SetSingleton(_actionManager.Object); _hc.SetSingleton(_handlerFactory.Object); diff --git a/src/Test/L0/Worker/CreateStepSummaryCommandL0.cs b/src/Test/L0/Worker/CreateStepSummaryCommandL0.cs index 67631ed4b..40b067afa 100644 --- a/src/Test/L0/Worker/CreateStepSummaryCommandL0.cs +++ b/src/Test/L0/Worker/CreateStepSummaryCommandL0.cs @@ -247,12 +247,16 @@ namespace GitHub.Runner.Common.Tests.Worker WriteDebug = true, Variables = _variables, }); - _executionContext.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) - .Callback((DTWebApi.Issue issue, string logMessage) => + _executionContext.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) + .Callback((DTWebApi.Issue issue, ExecutionContextLogOptions logOptions) => { - _issues.Add(new Tuple(issue, logMessage)); - var message = !string.IsNullOrEmpty(logMessage) ? logMessage : issue.Message; - _trace.Info($"Issue '{issue.Type}': {message}"); + var resolvedMessage = issue.Message; + if (logOptions.WriteToLog && !string.IsNullOrEmpty(logOptions.LogMessageOverride)) + { + resolvedMessage = logOptions.LogMessageOverride; + } + _issues.Add(new(issue, resolvedMessage)); + _trace.Info($"Issue '{issue.Type}': {resolvedMessage}"); }); _executionContext.Setup(x => x.Write(It.IsAny(), It.IsAny())) .Callback((string tag, string message) => @@ -268,4 +272,4 @@ namespace GitHub.Runner.Common.Tests.Worker return hostContext; } } -} \ No newline at end of file +} diff --git a/src/Test/L0/Worker/ExecutionContextL0.cs b/src/Test/L0/Worker/ExecutionContextL0.cs index 649e66c86..2bdbd9f44 100644 --- a/src/Test/L0/Worker/ExecutionContextL0.cs +++ b/src/Test/L0/Worker/ExecutionContextL0.cs @@ -1,4 +1,4 @@ -using System; +using System; using System.Collections.Generic; using System.Linq; using System.Runtime.CompilerServices; @@ -52,42 +52,43 @@ namespace GitHub.Runner.Common.Tests.Worker // Act. ec.InitializeJob(jobRequest, CancellationToken.None); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); + // Flood the ExecutionContext with errors and warnings (past its max capacity of 10). + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); ec.Complete(); // Assert. - jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.ErrorCount == 15)), Times.AtLeastOnce); - jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.WarningCount == 14)), Times.AtLeastOnce); + jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.ErrorCount > 0)), Times.AtLeast(10)); + jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.WarningCount > 0)), Times.AtLeast(10)); jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.Issues.Where(i => i.Type == IssueType.Error).Count() == 10)), Times.AtLeastOnce); jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.Issues.Where(i => i.Type == IssueType.Warning).Count() == 10)), Times.AtLeastOnce); } @@ -190,9 +191,9 @@ namespace GitHub.Runner.Common.Tests.Worker bigMessage += "a"; } - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = bigMessage }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = bigMessage }); - ec.AddIssue(new Issue() { Type = IssueType.Notice, Message = bigMessage }); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = bigMessage }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = bigMessage }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Notice, Message = bigMessage }, ExecutionContextLogOptions.Default); ec.Complete(); @@ -203,6 +204,61 @@ namespace GitHub.Runner.Common.Tests.Worker } } + [Fact] + [Trait("Level", "L0")] + [Trait("Category", "Worker")] + public void AddIssue_OverrideLogMessage() + { + using (TestHostContext hc = CreateTestContext()) + { + // Arrange: Create a job request message. + TaskOrchestrationPlanReference plan = new(); + TimelineReference timeline = new(); + Guid jobId = Guid.NewGuid(); + string jobName = "some job name"; + var jobRequest = new Pipelines.AgentJobRequestMessage(plan, timeline, jobId, jobName, jobName, null, null, null, new Dictionary(), new List(), new Pipelines.JobResources(), new Pipelines.ContextData.DictionaryContextData(), new Pipelines.WorkspaceOptions(), new List(), null, null, null, null); + jobRequest.Resources.Repositories.Add(new Pipelines.RepositoryResource() + { + Alias = Pipelines.PipelineConstants.SelfAlias, + Id = "github", + Version = "sha1" + }); + jobRequest.ContextData["github"] = new Pipelines.ContextData.DictionaryContextData(); + + // Arrange: Setup the paging logger. + var pagingLogger = new Mock(); + var jobServerQueue = new Mock(); + + hc.EnqueueInstance(pagingLogger.Object); + hc.SetSingleton(jobServerQueue.Object); + + var ec = new Runner.Worker.ExecutionContext(); + ec.Initialize(hc); + + // Act. + ec.InitializeJob(jobRequest, CancellationToken.None); + + var issueMessage = "Message embedded in issue."; + var overrideMessage = "Message override."; + var options = new ExecutionContextLogOptions(true, overrideMessage); + + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = issueMessage }, options); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = issueMessage }, options); + ec.AddIssue(new Issue() { Type = IssueType.Notice, Message = issueMessage }, options); + + // Finally, add a variation that DOESN'T override the message. + ec.AddIssue(new Issue() { Type = IssueType.Notice, Message = issueMessage }, ExecutionContextLogOptions.Default); + + ec.Complete(); + + // Assert. + jobServerQueue.Verify(x => x.QueueWebConsoleLine(It.IsAny(), It.IsAny(), It.IsAny()), Times.Exactly(4)); + jobServerQueue.Verify(x => x.QueueWebConsoleLine(It.IsAny(), It.Is(text => text.EndsWith(overrideMessage)), It.IsAny()), Times.Exactly(3)); + jobServerQueue.Verify(x => x.QueueWebConsoleLine(It.IsAny(), It.Is(text => text.EndsWith(issueMessage)), It.IsAny()), Times.Exactly(1)); + } + } + + [Fact] [Trait("Level", "L0")] [Trait("Category", "Worker")] @@ -242,13 +298,15 @@ namespace GitHub.Runner.Common.Tests.Worker var embeddedStep = ec.CreateChild(Guid.NewGuid(), "action_1_pre", "action_1_pre", null, null, ActionRunStage.Main, isEmbedded: true); embeddedStep.Start(); - embeddedStep.AddIssue(new Issue() { Type = IssueType.Error, Message = "error annotation that should have step and line number information" }); - embeddedStep.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning annotation that should have step and line number information" }); - embeddedStep.AddIssue(new Issue() { Type = IssueType.Notice, Message = "notice annotation that should have step and line number information" }); + embeddedStep.AddIssue(new Issue() { Type = IssueType.Error, Message = "error annotation that should have step and line number information" }, ExecutionContextLogOptions.Default); + embeddedStep.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning annotation that should have step and line number information" }, ExecutionContextLogOptions.Default); + embeddedStep.AddIssue(new Issue() { Type = IssueType.Notice, Message = "notice annotation that should have step and line number information" }, ExecutionContextLogOptions.Default); - jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.Issues.Where(i => i.Data.ContainsKey("stepNumber") && i.Data.ContainsKey("logFileLineNumber") && i.Type == IssueType.Error).Count() == 1)), Times.AtLeastOnce); - jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.Issues.Where(i => i.Data.ContainsKey("stepNumber") && i.Data.ContainsKey("logFileLineNumber") && i.Type == IssueType.Warning).Count() == 1)), Times.AtLeastOnce); - jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.Issues.Where(i => i.Data.ContainsKey("stepNumber") && i.Data.ContainsKey("logFileLineNumber") && i.Type == IssueType.Notice).Count() == 1)), Times.AtLeastOnce); + jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.IsAny()), Times.AtLeastOnce); + // Verify that Error/Warning/Notice issues added to embedded steps don't get sent up to the server. + jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.Issues.Where(i => i.Data.ContainsKey("stepNumber") && i.Data.ContainsKey("logFileLineNumber") && i.Type == IssueType.Error).Count() == 1)), Times.Never); + jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.Issues.Where(i => i.Data.ContainsKey("stepNumber") && i.Data.ContainsKey("logFileLineNumber") && i.Type == IssueType.Warning).Count() == 1)), Times.Never); + jobServerQueue.Verify(x => x.QueueTimelineRecordUpdate(It.IsAny(), It.Is(t => t.Issues.Where(i => i.Data.ContainsKey("stepNumber") && i.Data.ContainsKey("logFileLineNumber") && i.Type == IssueType.Notice).Count() == 1)), Times.Never); } } @@ -626,12 +684,12 @@ namespace GitHub.Runner.Common.Tests.Worker ec.StepTelemetry.StepId = Guid.NewGuid(); ec.StepTelemetry.Stage = "main"; - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Notice, Message = "notice" }); - ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - ec.AddIssue(new Issue() { Type = IssueType.Notice, Message = "notice" }); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Notice, Message = "notice" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + ec.AddIssue(new Issue() { Type = IssueType.Notice, Message = "notice" }, ExecutionContextLogOptions.Default); ec.Complete(); @@ -692,9 +750,9 @@ namespace GitHub.Runner.Common.Tests.Worker embeddedStep.StepTelemetry.Action = "actions/checkout"; embeddedStep.StepTelemetry.Ref = "v2"; - embeddedStep.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - embeddedStep.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - embeddedStep.AddIssue(new Issue() { Type = IssueType.Notice, Message = "notice" }); + embeddedStep.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + embeddedStep.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + embeddedStep.AddIssue(new Issue() { Type = IssueType.Notice, Message = "notice" }, ExecutionContextLogOptions.Default); embeddedStep.PublishStepTelemetry(); @@ -756,9 +814,9 @@ namespace GitHub.Runner.Common.Tests.Worker embeddedStep.StepTelemetry.Action = "actions/checkout"; embeddedStep.StepTelemetry.Ref = "v2"; - embeddedStep.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }); - embeddedStep.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }); - embeddedStep.AddIssue(new Issue() { Type = IssueType.Notice, Message = "notice" }); + embeddedStep.AddIssue(new Issue() { Type = IssueType.Error, Message = "error" }, ExecutionContextLogOptions.Default); + embeddedStep.AddIssue(new Issue() { Type = IssueType.Warning, Message = "warning" }, ExecutionContextLogOptions.Default); + embeddedStep.AddIssue(new Issue() { Type = IssueType.Notice, Message = "notice" }, ExecutionContextLogOptions.Default); ec.Complete(); @@ -927,7 +985,7 @@ namespace GitHub.Runner.Common.Tests.Worker inputVarsContext["VARIABLE_2"] = new StringContextData("value2"); jobRequest.ContextData["vars"] = inputVarsContext; - // Arrange: Setup the paging logger. + // Arrange: Setup the paging logger. var pagingLogger1 = new Mock(); var jobServerQueue = new Mock(); hc.EnqueueInstance(pagingLogger1.Object); @@ -941,7 +999,7 @@ namespace GitHub.Runner.Common.Tests.Worker var expected = new DictionaryContextData(); expected["VARIABLE_1"] = new StringContextData("value1"); expected["VARIABLE_2"] = new StringContextData("value1"); - + Assert.True(ExpressionValuesAssertEqual(expected, jobContext.ExpressionValues["vars"] as DictionaryContextData)); } } @@ -972,7 +1030,7 @@ namespace GitHub.Runner.Common.Tests.Worker inputVarsContext[Constants.Variables.Actions.RunnerDebug] = new StringContextData("true"); jobRequest.ContextData["vars"] = inputVarsContext; - // Arrange: Setup the paging logger. + // Arrange: Setup the paging logger. var pagingLogger1 = new Mock(); var jobServerQueue = new Mock(); hc.EnqueueInstance(pagingLogger1.Object); @@ -983,7 +1041,7 @@ namespace GitHub.Runner.Common.Tests.Worker jobContext.InitializeJob(jobRequest, CancellationToken.None); - + Assert.Equal("true", jobContext.Global.Variables.Get(Constants.Variables.Actions.StepDebug)); Assert.Equal("true", jobContext.Global.Variables.Get(Constants.Variables.Actions.RunnerDebug)); } @@ -1018,7 +1076,7 @@ namespace GitHub.Runner.Common.Tests.Worker jobRequest.Variables[Constants.Variables.Actions.StepDebug] = "false"; jobRequest.Variables[Constants.Variables.Actions.RunnerDebug] = "false"; - // Arrange: Setup the paging logger. + // Arrange: Setup the paging logger. var pagingLogger1 = new Mock(); var jobServerQueue = new Mock(); hc.EnqueueInstance(pagingLogger1.Object); @@ -1029,7 +1087,7 @@ namespace GitHub.Runner.Common.Tests.Worker jobContext.InitializeJob(jobRequest, CancellationToken.None); - + Assert.Equal("false", jobContext.Global.Variables.Get(Constants.Variables.Actions.StepDebug)); Assert.Equal("false", jobContext.Global.Variables.Get(Constants.Variables.Actions.RunnerDebug)); } @@ -1061,4 +1119,4 @@ namespace GitHub.Runner.Common.Tests.Worker return true; } } -} \ No newline at end of file +} diff --git a/src/Test/L0/Worker/OutputManagerL0.cs b/src/Test/L0/Worker/OutputManagerL0.cs index 8bac93933..cf233bb55 100644 --- a/src/Test/L0/Worker/OutputManagerL0.cs +++ b/src/Test/L0/Worker/OutputManagerL0.cs @@ -984,10 +984,15 @@ namespace GitHub.Runner.Common.Tests.Worker { _onMatcherChanged = handler; }); - _executionContext.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) - .Callback((DTWebApi.Issue issue, string logMessage) => + _executionContext.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) + .Callback((DTWebApi.Issue issue, ExecutionContextLogOptions logOptions) => { - _issues.Add(new Tuple(issue, logMessage)); + var resolvedMessage = issue.Message; + if (logOptions.WriteToLog && !string.IsNullOrEmpty(logOptions.LogMessageOverride)) + { + resolvedMessage = logOptions.LogMessageOverride; + } + _issues.Add(new(issue, resolvedMessage)); }); _executionContext.Setup(x => x.Write(It.IsAny(), It.IsAny())) .Callback((string tag, string message) => diff --git a/src/Test/L0/Worker/SaveStateFileCommandL0.cs b/src/Test/L0/Worker/SaveStateFileCommandL0.cs index 45296c709..2e7767e57 100644 --- a/src/Test/L0/Worker/SaveStateFileCommandL0.cs +++ b/src/Test/L0/Worker/SaveStateFileCommandL0.cs @@ -413,12 +413,16 @@ namespace GitHub.Runner.Common.Tests.Worker EnvironmentVariables = new Dictionary(VarUtil.EnvironmentVariableKeyComparer), WriteDebug = true, }); - _executionContext.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) - .Callback((DTWebApi.Issue issue, string logMessage) => + _executionContext.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) + .Callback((DTWebApi.Issue issue, ExecutionContextLogOptions logOptions) => { - _issues.Add(new Tuple(issue, logMessage)); - var message = !string.IsNullOrEmpty(logMessage) ? logMessage : issue.Message; - _trace.Info($"Issue '{issue.Type}': {message}"); + var resolvedMessage = issue.Message; + if (logOptions.WriteToLog && !string.IsNullOrEmpty(logOptions.LogMessageOverride)) + { + resolvedMessage = logOptions.LogMessageOverride; + } + _issues.Add(new(issue, resolvedMessage)); + _trace.Info($"Issue '{issue.Type}': {resolvedMessage}"); }); _executionContext.Setup(x => x.Write(It.IsAny(), It.IsAny())) .Callback((string tag, string message) => diff --git a/src/Test/L0/Worker/SetEnvFileCommandL0.cs b/src/Test/L0/Worker/SetEnvFileCommandL0.cs index 41f8499d5..805f9e859 100644 --- a/src/Test/L0/Worker/SetEnvFileCommandL0.cs +++ b/src/Test/L0/Worker/SetEnvFileCommandL0.cs @@ -411,12 +411,16 @@ namespace GitHub.Runner.Common.Tests.Worker EnvironmentVariables = new Dictionary(VarUtil.EnvironmentVariableKeyComparer), WriteDebug = true, }); - _executionContext.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) - .Callback((DTWebApi.Issue issue, string logMessage) => + _executionContext.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) + .Callback((DTWebApi.Issue issue, ExecutionContextLogOptions logOptions) => { - _issues.Add(new Tuple(issue, logMessage)); - var message = !string.IsNullOrEmpty(logMessage) ? logMessage : issue.Message; - _trace.Info($"Issue '{issue.Type}': {message}"); + var resolvedMessage = issue.Message; + if (logOptions.WriteToLog && !string.IsNullOrEmpty(logOptions.LogMessageOverride)) + { + resolvedMessage = logOptions.LogMessageOverride; + } + _issues.Add(new(issue, resolvedMessage)); + _trace.Info($"Issue '{issue.Type}': {resolvedMessage}"); }); _executionContext.Setup(x => x.Write(It.IsAny(), It.IsAny())) .Callback((string tag, string message) => diff --git a/src/Test/L0/Worker/SetOutputFileCommandL0.cs b/src/Test/L0/Worker/SetOutputFileCommandL0.cs index 8af9695db..9831f45de 100644 --- a/src/Test/L0/Worker/SetOutputFileCommandL0.cs +++ b/src/Test/L0/Worker/SetOutputFileCommandL0.cs @@ -413,12 +413,16 @@ namespace GitHub.Runner.Common.Tests.Worker EnvironmentVariables = new Dictionary(VarUtil.EnvironmentVariableKeyComparer), WriteDebug = true, }); - _executionContext.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) - .Callback((DTWebApi.Issue issue, string logMessage) => + _executionContext.Setup(x => x.AddIssue(It.IsAny(), It.IsAny())) + .Callback((DTWebApi.Issue issue, ExecutionContextLogOptions logOptions) => { - _issues.Add(new Tuple(issue, logMessage)); - var message = !string.IsNullOrEmpty(logMessage) ? logMessage : issue.Message; - _trace.Info($"Issue '{issue.Type}': {message}"); + var resolvedMessage = issue.Message; + if (logOptions.WriteToLog && !string.IsNullOrEmpty(logOptions.LogMessageOverride)) + { + resolvedMessage = logOptions.LogMessageOverride; + } + _issues.Add(new(issue, resolvedMessage)); + _trace.Info($"Issue '{issue.Type}': {resolvedMessage}"); }); _executionContext.Setup(x => x.Write(It.IsAny(), It.IsAny())) .Callback((string tag, string message) => @@ -430,8 +434,8 @@ namespace GitHub.Runner.Common.Tests.Worker _executionContext.Setup(x => x.SetOutput(It.IsAny(), It.IsAny(), out reference)) .Callback((string name, string value, out string reference) => { - reference = value; - _outputs[name] = value; + reference = value; + _outputs[name] = value; }); // SetOutputFileCommand diff --git a/src/Test/L0/Worker/StepsRunnerL0.cs b/src/Test/L0/Worker/StepsRunnerL0.cs index 3ff1e304a..d17ea3e2c 100644 --- a/src/Test/L0/Worker/StepsRunnerL0.cs +++ b/src/Test/L0/Worker/StepsRunnerL0.cs @@ -1,4 +1,4 @@ -using System; +using System; using System.Collections.Generic; using System.Globalization; using System.Linq; @@ -337,7 +337,7 @@ namespace GitHub.Runner.Common.Tests.Worker // Act. await _stepsRunner.RunAsync(jobContext: _ec.Object); - // Assert. + // Assert. Assert.Equal(2, variableSet.Step.Length); variableSet.Step[0].Verify(x => x.RunAsync()); variableSet.Step[1].Verify(x => x.RunAsync(), variableSet.Expected ? Times.Once() : Times.Never()); @@ -590,7 +590,7 @@ namespace GitHub.Runner.Common.Tests.Worker step.Setup(x => x.Condition).Returns(condition); step.Setup(x => x.ContinueOnError).Returns(new BooleanToken(null, null, null, continueOnError)); step.Setup(x => x.Action) - .Returns(new DistributedTask.Pipelines.ActionStep() + .Returns(new GitHub.DistributedTask.Pipelines.ActionStep() { Name = name, Id = Guid.NewGuid(), diff --git a/src/Test/TestData/timelinerecord_json_samples.yml b/src/Test/TestData/timelinerecord_json_samples.yml new file mode 100644 index 000000000..124c45936 --- /dev/null +++ b/src/Test/TestData/timelinerecord_json_samples.yml @@ -0,0 +1,70 @@ +minimal: | + { "Name": "minimal" } +invalid-attempt-value: | + { + "Name": "invalid-attempt-value", + "Attempt": -99 + } +zero-attempt-value: | + { + "Name": "zero-attempt-value", + "Attempt": 0 + } +legacy-nulls: | + { + "Name": "legacy-nulls", + "ErrorCount": null, + "WarningCount": null, + "NoticeCount": null + } +missing-counts: | + { + "Name": "missing-counts" + } +non-zero-counts: | + { + "Name": "non-zero-counts", + "ErrorCount": 10, + "WarningCount": 20, + "NoticeCount": 30 + } +explicit-null-collections: | + { + "Name": "explicit-null-collections", + "Issues": null, + "PreviousAttempts": null, + "Variables": null + } +lean: | + { + "Id": "00000000-0000-0000-0000-000000000000", + "Name": "lean", + "LastModified": "\/Date(1679073003252+0000)\/", + "Issues": [ + { + "Type": 0, + "Category": null, + "Message": null, + "IsInfrastructureIssue": null + } + ], + "Variables": [ + { "Key": "x", "Value": { "Value": "1" } }, + { "Key": "y", "Value": { "Value": "2" } }, + { "Key": "z", "Value": { "Value": "3" } } + ], + "Attempt": 4, + "PreviousAttempts": [ + { "Attempt": 1 }, + { "Attempt": 2 }, + { "Attempt": 3 } + ] + } +duplicate-variable-keys: | + { + "Name": "duplicate-variable-keys", + "Variables": [ + { "Key": "aaa", "Value": { "Value": "a.1" } }, + { "Key": "AAA", "Value": { "Value": "a.2" } } + ] + } \ No newline at end of file