Skip to content
48 changes: 24 additions & 24 deletions src/Microsoft.DotNet.Helix/JobMonitor/JobMonitorRunner.cs
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,9 @@ namespace Microsoft.DotNet.Helix.JobMonitor
{
internal sealed class JobMonitorRunner : IJobMonitorRunner, IDisposable
{
private const string AzdoWarningPrefix = "##vso[task.logissue type=warning]";
private const string AzdoErrorPrefix = "##vso[task.logissue type=error]";

private readonly JobMonitorOptions _options;
private readonly ILogger _logger;
private readonly IAzureDevOpsService _azdo;
Expand Down Expand Up @@ -173,7 +176,7 @@ private async Task CancelInFlightHelixJobsAsync(
return;
}

_logger.LogWarning("Cancellation requested. Attempting to cancel {Count} in-flight Helix job(s).", inFlightJobs.Count);
LogWarning($"Cancellation requested. Attempting to cancel {inFlightJobs.Count} in-flight Helix job(s).");

Task[] cancelTasks =
[
Expand All @@ -191,7 +194,7 @@ private async Task CancelInFlightHelixJobsAsync(
}
catch (Exception ex)
{
_logger.LogWarning(ex, "Failed to cancel Helix job {JobName}.", job.DisplayName);
LogWarning(ex, $"Failed to cancel Helix job {job.DisplayName}.");
}
})
];
Expand Down Expand Up @@ -315,7 +318,7 @@ private async Task<int> RunLoopAsync(

if (anyNonMonitorJobFailures)
{
_logger.LogError("One or more non-monitor pipeline jobs failed.");
LogError("One or more non-monitor pipeline jobs failed.");
return 1;
}

Expand Down Expand Up @@ -702,12 +705,7 @@ private void LogFailedWorkItemConsoleLinks(HelixJobInfo helixJob, IReadOnlyColle
continue;
}

_logger.LogInformation("❌ Work item '{WorkItemName}' in job '{JobName}' failed ({State}).{nl}Console: {ConsoleOutputUri}",
workItem.Name,
helixJob.DisplayName,
FormatWorkItemState(workItem),
Environment.NewLine,
GetConsoleOutputText(workItem.ConsoleOutputUri));
LogWarning($"Work item '{workItem.Name}' in job '{helixJob.DisplayName}' failed ({FormatWorkItemState(workItem)}).{Environment.NewLine}Console: {GetConsoleOutputText(workItem.ConsoleOutputUri)}");
Comment thread
premun marked this conversation as resolved.
}
}

Expand Down Expand Up @@ -818,11 +816,7 @@ private void LogFinalFailedWorkItemConsoleInfo()
lines.Add($"{(i == failures.Count - 1 ? " " : "│ ")}└─ Console: {failure.ConsoleOutput}");
}

_logger.LogError("❌ Failed work item console logs:{nl}Test results: {TestResultsUri}{nl}{FailedWorkItemConsoleLogs}",
Environment.NewLine,
GetTestResultsUri(),
Environment.NewLine,
string.Join(Environment.NewLine, lines));
LogError($"Failed work item console logs:{Environment.NewLine}Test results: {GetTestResultsUri()}{Environment.NewLine}{string.Join(Environment.NewLine, lines)}");
}

private string GetTestResultsUri()
Expand Down Expand Up @@ -981,20 +975,14 @@ private void ReportTimeout(

if (unfinishedHelixJobs.Count > 0)
{
_logger.LogError(
$"Helix Job Monitor timed out after {{TimeoutMinutes}} minute(s) ({{Timeout}}). {{UnfinishedCount}} Helix job(s) were unfinished or unprocessed:{Environment.NewLine}- {{UnfinishedJobs}}{Environment.NewLine}",
timeout.TotalMinutes,
timeout,
unfinishedHelixJobs.Count,
string.Join(Environment.NewLine + "- ", unfinishedHelixJobs.Select(FormatUnfinishedHelixJobForTimeoutLog)));
LogError(
$"Helix Job Monitor timed out after {timeout.TotalMinutes} minute(s) ({timeout}). {unfinishedHelixJobs.Count} Helix job(s) were unfinished or unprocessed:{Environment.NewLine}- {string.Join(Environment.NewLine + "- ", unfinishedHelixJobs.Select(FormatUnfinishedHelixJobForTimeoutLog))}{Environment.NewLine}");
}

if (inProgressPipelineJobs.Count > 0)
{
_logger.LogError(
$"At timeout, {{InProgressCount}} non-monitor Azure DevOps pipeline job(s) were still in progress or queued:{Environment.NewLine}- {{InProgressJobs}}{Environment.NewLine}",
inProgressPipelineJobs.Count,
string.Join(Environment.NewLine + "- ", inProgressPipelineJobs.Select(FormatInProgressPipelineJobForTimeoutLog)));
LogError(
$"At timeout, {inProgressPipelineJobs.Count} non-monitor Azure DevOps pipeline job(s) were still in progress or queued:{Environment.NewLine}- {string.Join(Environment.NewLine + "- ", inProgressPipelineJobs.Select(FormatInProgressPipelineJobForTimeoutLog))}{Environment.NewLine}");
}
}

Expand Down Expand Up @@ -1023,6 +1011,18 @@ private static string FormatInProgressPipelineJobForTimeoutLog(AzureDevOpsTimeli
return $"{name} [state={state}, result={result}]";
}

private void LogWarning(string message)
=> _logger.LogWarning("{Prefix}{Message}", AzdoWarningPrefix, message);

Comment thread
premun marked this conversation as resolved.
private void LogWarning(Exception exception, string message)
=> _logger.LogWarning(exception, "{Prefix}{Message}", AzdoWarningPrefix, message);

Comment thread
premun marked this conversation as resolved.
private void LogError(string message)
=> _logger.LogError("{Prefix}{Message}", AzdoErrorPrefix, message);

private void LogError(Exception exception, string message)
=> _logger.LogError(exception, "{Prefix}{Message}", AzdoErrorPrefix, message);

public void Dispose()
{
(_azdo as IDisposable)?.Dispose();
Expand Down
9 changes: 7 additions & 2 deletions src/Microsoft.DotNet.Helix/JobMonitor/Program.cs
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,8 @@ namespace Microsoft.DotNet.Helix.JobMonitor
{
internal static class Program
{
private const string AzdoErrorPrefix = "##vso[task.logissue type=error]";

public static async Task<int> Main(string[] args)
{
JobMonitorOptions options = null;
Expand All @@ -23,7 +25,7 @@ public static async Task<int> Main(string[] args)
{
using ILoggerFactory errorLoggerFactory = CreateLoggerFactory(verbose: false);
ILogger errorLogger = errorLoggerFactory.CreateLogger<JobMonitorRunner>();
errorLogger.LogError(ex, "Helix Job Monitor terminated with an unhandled exception.");
LogError(errorLogger, ex, "Helix Job Monitor terminated with an unhandled exception.");
return 1;
}

Expand Down Expand Up @@ -91,7 +93,7 @@ public static async Task<int> Main(string[] args)
}
catch (Exception ex)
{
logger.LogError(ex, "Helix Job Monitor terminated with an unhandled exception.");
LogError(logger, ex, "Helix Job Monitor terminated with an unhandled exception.");
return 1;
}
}
Expand All @@ -106,5 +108,8 @@ private static ILoggerFactory CreateLoggerFactory(bool verbose)
.AddConsoleFormatter<CompactConsoleLoggerFormatter, SimpleConsoleFormatterOptions>();
});
}

private static void LogError(ILogger logger, Exception exception, string message)
=> logger.LogError(exception, "{Prefix}{Message}", AzdoErrorPrefix, message);
Comment thread
premun marked this conversation as resolved.
Comment thread
premun marked this conversation as resolved.
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -1329,6 +1329,7 @@ public async Task MonitorTimesOut_DoesNotReportOrCancelJobsThatFinishedAfterFirs
// cached snapshot was overwritten with the latest (finished) state.
string timeoutMessage = logger.Messages.Should().ContainSingle(m =>
m.Contains("Helix Job Monitor timed out", StringComparison.Ordinal)).Subject;
timeoutMessage.Should().StartWith("##vso[task.logissue type=error]");
timeoutMessage.Should().Contain("helix-stuck");
Comment thread
premun marked this conversation as resolved.
timeoutMessage.Should().NotContain("helix-good");

Expand Down Expand Up @@ -2638,11 +2639,15 @@ public async Task CompletedHelixJob_LogsFailedWorkItemConsoleLinks()
&& message.Contains("https://helix.example/wi-pass/console", StringComparison.Ordinal));
logger.Messages.Should().Contain(message =>
message.Contains($"Work item 'wi-fail' in job 'helix-linux' failed (Finished, exit code 1).{Environment.NewLine}Console: https://helix.example/wi-fail/console", StringComparison.Ordinal));
logger.Messages.Should().Contain(message =>
message.Contains("##vso[task.logissue type=warning]Work item 'wi-fail' in job 'helix-linux' failed", StringComparison.Ordinal));
logger.Messages.Should().Contain(message =>
message.Contains("Failed work item console logs:", StringComparison.Ordinal)
&& message.Contains("Test results: https://dev.azure.com/dnceng/public/_build/results?buildId=123&view=ms.vss-test-web.build-test-results-tab", StringComparison.Ordinal)
&& message.Contains("└─ wi-fail (Job: helix-linux) (Finished, exit code 1)", StringComparison.Ordinal)
&& message.Contains("└─ Console: https://helix.example/wi-fail/console", StringComparison.Ordinal));
logger.Messages.Should().Contain(message =>
message.Contains("##vso[task.logissue type=error]Failed work item console logs:", StringComparison.Ordinal));
logger.Messages.Should().NotContain(message =>
message.Contains("Helix job: helix-linux", StringComparison.Ordinal));
}
Expand Down
Loading