Skip to content
5 changes: 2 additions & 3 deletions src/Runner.Common/JobServerQueue.cs
Original file line number Diff line number Diff line change
Expand Up @@ -299,7 +299,7 @@ private async Task ProcessWebConsoleLinesQueueAsync(bool runOnce = false)
{
try
{
// Give at most 60s for each request.
// Give at most 60s for each request.
using (var timeoutTokenSource = new CancellationTokenSource(TimeSpan.FromSeconds(60)))
{
await _jobServer.AppendTimelineRecordFeedAsync(_scopeIdentifier, _hubName, _planId, _jobTimelineId, _jobTimelineRecordId, stepRecordId, batch.Select(logLine => logLine.Line).ToList(), batch[0].LineNumber, timeoutTokenSource.Token);
Expand Down Expand Up @@ -600,8 +600,7 @@ private List<TimelineRecord> MergeTimelineRecords(List<TimelineRecord> timelineR
{
foreach (var issue in record.Issues)
{
String source;
issue.Data.TryGetValue("sourcepath", out source);
string source = issue["sourcepath"];
Trace.Verbose($" Issue: c={issue.Category}, t={issue.Type}, s={source ?? string.Empty}, m={issue.Message}");
}
}
Expand Down
10 changes: 5 additions & 5 deletions src/Runner.Listener/JobDispatcher.cs
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ public interface IJobDispatcher : IRunnerService
// This implementation of IJobDispatcher is not thread safe.
// It is based on the fact that the current design of the runner is a dequeue
// and processes one message from the message queue at a time.
// In addition, it only executes one job every time,
// In addition, it only executes one job every time,
// and the server will not send another job while this one is still running.
public sealed class JobDispatcher : RunnerService, IJobDispatcher
{
Expand Down Expand Up @@ -426,7 +426,7 @@ private async Task RunAsync(Pipelines.AgentJobRequestMessage message, string orc
{
workerOutput.Add(stdout.Data);
}

if (printToStdout)
{
term.WriteLine(stdout.Data, skipTracing: true);
Expand Down Expand Up @@ -512,7 +512,7 @@ await processChannel.SendAsync(
var accessToken = systemConnection?.Authorization?.Parameters["AccessToken"];
notification.JobStarted(message.JobId, accessToken, systemConnection.Url);

HostContext.WritePerfCounter($"SentJobToWorker_{requestId.ToString()}");
HostContext.WritePerfCounter($"SentJobToWorker_{requestId}");

try
{
Expand Down Expand Up @@ -620,7 +620,7 @@ await processChannel.SendAsync(
}
}

// wait worker to exit
// wait worker to exit
// if worker doesn't exit within timeout, then kill worker.
completedTask = await Task.WhenAny(workerProcessTask, Task.Delay(-1, workerCancelTimeoutKillToken));

Expand Down Expand Up @@ -1014,7 +1014,7 @@ private async Task LogWorkerProcessUnhandledException(IJobServer jobServer, Pipe
}

var unhandledExceptionIssue = new Issue() { Type = IssueType.Error, Message = errorMessage };
unhandledExceptionIssue.Data[Constants.Runner.InternalTelemetryIssueDataKey] = Constants.Runner.WorkerCrash;
unhandledExceptionIssue[Constants.Runner.InternalTelemetryIssueDataKey] = Constants.Runner.WorkerCrash;
jobRecord.ErrorCount++;
jobRecord.Issues.Add(unhandledExceptionIssue);
await jobServer.UpdateTimelineRecordsAsync(message.Plan.ScopeIdentifier, message.Plan.PlanType, message.Plan.PlanId, message.Timeline.Id, new TimelineRecord[] { jobRecord }, CancellationToken.None);
Expand Down
49 changes: 17 additions & 32 deletions src/Runner.Worker/ActionCommandManager.cs
Original file line number Diff line number Diff line change
Expand Up @@ -270,12 +270,9 @@ public void ProcessCommand(IExecutionContext context, string line, ActionCommand
if (string.Equals(blocked, envName, StringComparison.OrdinalIgnoreCase))
{
// Log Telemetry and let user know they shouldn't do this
var issue = new Issue()
{
Type = IssueType.Error,
Message = $"Can't update {blocked} environment variable using ::set-env:: command."
};
issue.Data[Constants.Runner.InternalTelemetryIssueDataKey] = $"{Constants.Runner.UnsupportedCommand}_{envName}";
var message = $"Can't update {blocked} environment variable using ::set-env:: command.";
var metadata = new IssueMetadata(Constants.Runner.InternalTelemetryIssueDataKey, $"{Constants.Runner.UnsupportedCommand}_{envName}");

@jww3 jww3 Jan 17, 2023

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I defined IssueMetadata as a data bucket to pass to CreateIssue It holds the seldom-used fields of an Issue. It was easier than polluting the CreateIssue function signature with those seldom-used fields.

You can pass a null IssueMetadata to CreateIssue if you don't have any of those seldom-used fields to send.

var issue = context.CreateIssue(IssueType.Error, message, metadata, true);
context.AddIssue(issue);

return;
Expand Down Expand Up @@ -309,12 +306,9 @@ public void ProcessCommand(IExecutionContext context, string line, ActionCommand
{
if (context.Global.Variables.GetBoolean("DistributedTask.DeprecateStepOutputCommands") ?? false)
{
var issue = new Issue()
{
Type = IssueType.Warning,
Message = String.Format(Constants.Runner.UnsupportedCommandMessage, this.Command)
};
issue.Data[Constants.Runner.InternalTelemetryIssueDataKey] = Constants.Runner.UnsupportedCommand;
var message = string.Format(Constants.Runner.UnsupportedCommandMessage, this.Command);
var metadata = new IssueMetadata(Constants.Runner.InternalTelemetryIssueDataKey, Constants.Runner.UnsupportedCommand);
var issue = context.CreateIssue(IssueType.Warning, message, metadata, true);
context.AddIssue(issue);
}

Expand Down Expand Up @@ -344,12 +338,9 @@ public void ProcessCommand(IExecutionContext context, string line, ActionCommand
{
if (context.Global.Variables.GetBoolean("DistributedTask.DeprecateStepOutputCommands") ?? false)
{
var issue = new Issue()
{
Type = IssueType.Warning,
Message = String.Format(Constants.Runner.UnsupportedCommandMessage, this.Command)
};
issue.Data[Constants.Runner.InternalTelemetryIssueDataKey] = Constants.Runner.UnsupportedCommand;
var message = string.Format(Constants.Runner.UnsupportedCommandMessage, this.Command);
var metadata = new IssueMetadata(Constants.Runner.InternalTelemetryIssueDataKey, Constants.Runner.UnsupportedCommand);
var issue = context.CreateIssue(IssueType.Warning, message, metadata, true);
context.AddIssue(issue);
}

Expand Down Expand Up @@ -618,16 +609,11 @@ public void ProcessCommand(IExecutionContext context, string inputLine, ActionCo
context.Debug("Enhanced Annotations not enabled on the server. The 'title', 'end_line', and 'end_column' fields are unsupported.");
}

Issue issue = new()
{
Category = "General",
Type = this.Type,
Message = command.Data
};
var issueCategory = "General";

if (!string.IsNullOrEmpty(file))
{
issue.Category = "Code";
issueCategory = "Code";

if (container != null)
{
Expand Down Expand Up @@ -658,14 +644,13 @@ public void ProcessCommand(IExecutionContext context, string inputLine, ActionCo
}
}

foreach (var property in command.Properties)
{
if (!string.Equals(property.Key, Constants.Runner.InternalTelemetryIssueDataKey, StringComparison.OrdinalIgnoreCase))
{
issue.Data[property.Key] = property.Value;
}
}
string keyToExclude = Constants.Runner.InternalTelemetryIssueDataKey;
var filteredDictionaryEntries = command.Properties
.Where(kvp => !string.Equals(kvp.Key, keyToExclude, StringComparison.OrdinalIgnoreCase))
.ToList();

var metadata = new IssueMetadata(issueCategory, false, null, filteredDictionaryEntries);
var issue = context.CreateIssue(this.Type, command.Data, metadata, true);
context.AddIssue(issue);
}

Expand Down
2 changes: 1 addition & 1 deletion src/Runner.Worker/ActionManager.cs
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
using System;
using System.Collections.Generic;
using System.IO;
using System.IO.Compression;
using System.IO.Compression; // required for OS_WINDOWS
using System.Linq;
using System.Net;
using System.Net.Http;
Expand Down
3 changes: 1 addition & 2 deletions src/Runner.Worker/DiagnosticLogManager.cs
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,6 @@
using GitHub.DistributedTask.WebApi;
using System.Linq;
using System.Globalization;
using System.Threading.Tasks;
using Pipelines = GitHub.DistributedTask.Pipelines;
using GitHub.Runner.Common;
using GitHub.Runner.Sdk;
Expand All @@ -32,7 +31,7 @@ public sealed class DiagnosticLogManager : RunnerService, IDiagnosticLogManager
{
private static string DateTimeFormat = "yyyyMMdd-HHmmss";
public void UploadDiagnosticLogs(IExecutionContext executionContext,
IExecutionContext parentContext,
IExecutionContext parentContext,
Pipelines.AgentJobRequestMessage message,
DateTime jobStartTimeUtc)
{
Expand Down
126 changes: 63 additions & 63 deletions src/Runner.Worker/ExecutionContext.cs
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@
using GitHub.Runner.Sdk;
using GitHub.Runner.Worker.Container;
using GitHub.Runner.Worker.Handlers;
using GitHub.Services.Common;
using Newtonsoft.Json;
using ObjectTemplating = GitHub.DistributedTask.ObjectTemplating;
using Pipelines = GitHub.DistributedTask.Pipelines;
Expand Down Expand Up @@ -90,7 +91,8 @@ public interface IExecutionContext : IRunnerService
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);
IReadOnlyIssue CreateIssue(IssueType issueType, string rawMessage, IssueMetadata metadata, bool writeToLog);
void AddIssue(IReadOnlyIssue issue);
void Progress(int percentage, string currentOperation = null);
void UpdateDetailTimelineRecord(TimelineRecord record);

Expand Down Expand Up @@ -124,7 +126,7 @@ public sealed class ExecutionContext : RunnerService, IExecutionContext

private readonly TimelineRecord _record = new();
private readonly Dictionary<Guid, TimelineRecord> _detailRecords = new();
private readonly List<Issue> _embeddedIssueCollector;
private readonly List<IReadOnlyIssue> _embeddedIssueCollector;
private readonly object _loggerLock = new();
private readonly object _matchersLock = new();
private readonly ExecutionContext _parentExecutionContext;
Expand Down Expand Up @@ -577,74 +579,77 @@ public void Progress(int percentage, string currentOperation = null)
_jobServerQueue.QueueTimelineRecordUpdate(_mainTimelineId, _record);
}

// This is not thread safe, the caller need to take lock before calling issue()
public void AddIssue(Issue issue, string logMessage = null)
// This is not thread safe, the caller needs to take lock before calling issue()
public IReadOnlyIssue CreateIssue(IssueType issueType, string rawMessage, IssueMetadata metadata, bool writeToLog)

@jww3 jww3 Jan 17, 2023

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This writeToLog argument represents the last-remaining side-effect. However, in every case existing callers pass true for writeToLog when calling CreateIssue.

Side-effect or otherwise, the usage pattern is consistent, so there doesn't appear to be a compelling case to address this (e.g. split this functionality out into its own function).

{
ArgUtil.NotNull(issue, nameof(issue));
string refinedMessage = PrimitiveExtensions.TrimExcess(HostContext.SecretMasker.MaskSecrets(rawMessage), _maxIssueMessageLength);

if (string.IsNullOrEmpty(logMessage))
{
logMessage = issue.Message;
}
var result = new Issue() {
Type = issueType,
Message = refinedMessage,
};

issue.Message = HostContext.SecretMasker.MaskSecrets(issue.Message);
if (issue.Message.Length > _maxIssueMessageLength)
if (metadata != null)
{
issue.Message = issue.Message[.._maxIssueMessageLength];
result.Category = metadata.Category;
result.IsInfrastructureIssue = metadata.IsInfrastructureIssue;
foreach (var kvp in metadata.Data)
{
result[kvp.Key] = kvp.Value;
}
}

// Tracking the line number (logFileLineNumber) and step number (stepNumber) for each issue that gets created
// Actions UI from the run summary page use both values to easily link to an exact locations in logs where annotations originate from
// It's important to keep track of the step number (key:stepNumber) and the line number (key:logFileLineNumber) of every issue that gets logged.
// Actions UI from the run summary page use both values to easily link to an exact locations in logs where annotations originate from.
if (_record.Order != null)
{
issue.Data["stepNumber"] = _record.Order.ToString();
result["stepNumber"] = _record.Order.ToString();
}

if (issue.Type == IssueType.Error)
string wellKnownTag = null;
Int32? previousCountForIssueType = null;
switch (issueType)
{
if (!string.IsNullOrEmpty(logMessage))
{
long logLineNumber = Write(WellKnownTags.Error, logMessage);
issue.Data["logFileLineNumber"] = logLineNumber.ToString();
}

if (_record.ErrorCount < _maxIssueCount)
{
_record.Issues.Add(issue);
}

_record.ErrorCount++;
case IssueType.Error:
wellKnownTag = WellKnownTags.Error;
previousCountForIssueType = _record.ErrorCount++;
break;
case IssueType.Warning:
wellKnownTag = WellKnownTags.Warning;
previousCountForIssueType = _record.WarningCount++;
break;
case IssueType.Notice:
wellKnownTag = WellKnownTags.Notice;
previousCountForIssueType = _record.NoticeCount++;
break;
}
else if (issue.Type == IssueType.Warning)

if (!string.IsNullOrEmpty(wellKnownTag))
{
if (!string.IsNullOrEmpty(logMessage))
if (writeToLog)
{
long logLineNumber = Write(WellKnownTags.Warning, logMessage);
issue.Data["logFileLineNumber"] = logLineNumber.ToString();
//Note that ::Write() has it's own secret masking logic
string logText = metadata?.LogMessageOverride ?? result.Message;
if (!string.IsNullOrEmpty(logText))
{
long logLineNumber = Write(wellKnownTag, logText);
result["logFileLineNumber"] = logLineNumber.ToString();
}
}

if (_record.WarningCount < _maxIssueCount)
if (previousCountForIssueType.GetValueOrDefault(0) < _maxIssueCount)
{
_record.Issues.Add(issue);
_record.Issues.Add(result);
}

_record.WarningCount++;
}
else if (issue.Type == IssueType.Notice)
{
if (!string.IsNullOrEmpty(logMessage))
{
long logLineNumber = Write(WellKnownTags.Notice, logMessage);
issue.Data["logFileLineNumber"] = logLineNumber.ToString();
}

if (_record.NoticeCount < _maxIssueCount)
{
_record.Issues.Add(issue);
}
return result;
}

_record.NoticeCount++;
}

// This is not thread safe, the caller needs to take lock before calling issue()
public void AddIssue(IReadOnlyIssue issue)
{
ArgUtil.NotNull(issue, nameof(issue));

// 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
Expand Down Expand Up @@ -1017,16 +1022,7 @@ public void PublishStepTelemetry()
if ((issue.Type == IssueType.Error || issue.Type == IssueType.Warning) &&
!string.IsNullOrEmpty(issue.Message))
{
string issueTelemetry;
if (issue.Message.Length > _maxIssueMessageLengthInTelemetry)
{
issueTelemetry = $"{issue.Message[.._maxIssueMessageLengthInTelemetry]}";
}
else
{
issueTelemetry = issue.Message;
}

string issueTelemetry = PrimitiveExtensions.TrimExcess(issue.Message, _maxIssueMessageLengthInTelemetry);
StepTelemetry.ErrorMessages.Add(issueTelemetry);

// Only send over the first 3 issues to avoid sending too much data.
Expand Down Expand Up @@ -1200,19 +1196,23 @@ public static void Error(this IExecutionContext context, Exception ex)
// 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 = context.CreateIssue(IssueType.Error, message, null, true);
context.AddIssue(issue);
}

// 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 metadata = new IssueMetadata(null, true, null, Enumerable.Empty<KeyValuePair<string, string>>());
var issue = context.CreateIssue(IssueType.Error, message, metadata, true);
context.AddIssue(issue);
}

// 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 = context.CreateIssue(IssueType.Warning, message, null, true);
context.AddIssue(issue);
}

// Do not add a format string overload. See comment on ExecutionContext.Write().
Expand Down
Loading