Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
25 changes: 24 additions & 1 deletion src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs
Original file line number Diff line number Diff line change
Expand Up @@ -147,7 +147,30 @@

if (workItem != null)
{
Log.LogError(FailureCategory.Test, $"Test {name} has failed. Check the Test tab or this console log: {workItem.GetMetadata("ConsoleOutputUri")}");
string consoleUri = workItem.GetMetadata("ConsoleOutputUri");
string consoleErrorText = workItem.GetMetadata("ConsoleErrorText");
string exitCode = workItem.GetMetadata("ExitCode");

var sb = new System.Text.StringBuilder();
sb.Append($"Test {name} has failed.");

if (!string.IsNullOrEmpty(exitCode))
{
sb.Append($" (exit code {exitCode})");
}

sb.Append($" Check the Test tab or this console log: {consoleUri}");

if (!string.IsNullOrEmpty(consoleErrorText))
{
sb.AppendLine();
sb.AppendLine("Error details:");

Check failure on line 167 in src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs

View check run for this annotation

Azure Pipelines / arcade-pr (Build Linux Build_Debug)

src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs#L167

src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs(167,57): error CS1513: (NETCORE_ENGINEERING_TELEMETRY=Build) } expected

Check failure on line 167 in src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs

View check run for this annotation

Azure Pipelines / arcade-pr (Build Linux Build_Debug)

src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs#L167

src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs(167,57): error CS1513: (NETCORE_ENGINEERING_TELEMETRY=Build) } expected
? consoleErrorText.Substring(0, 2000) + "..."

Check failure on line 168 in src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs

View check run for this annotation

Azure Pipelines / arcade-pr (Build Linux Build_Debug)

src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs#L168

src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs(168,74): error CS1002: (NETCORE_ENGINEERING_TELEMETRY=Build) ; expected

Check failure on line 168 in src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs

View check run for this annotation

Azure Pipelines / arcade-pr (Build Linux Build_Debug)

src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs#L168

src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs(168,74): error CS1513: (NETCORE_ENGINEERING_TELEMETRY=Build) } expected

Check failure on line 168 in src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs

View check run for this annotation

Azure Pipelines / arcade-pr (Build Linux Build_Debug)

src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs#L168

src/Microsoft.DotNet.Helix/Sdk/CheckAzurePipelinesTestResults.cs(168,74): error CS1002: (NETCORE_ENGINEERING_TELEMETRY=Build) ; expected
: consoleErrorText;
sb.Append(truncated);
}

Log.LogError(FailureCategory.Test, sb.ToString());
}
else
{
Expand Down
26 changes: 25 additions & 1 deletion src/Microsoft.DotNet.Helix/Sdk/CheckHelixJobStatus.cs
Original file line number Diff line number Diff line change
Expand Up @@ -40,8 +40,32 @@ protected override Task ExecuteCore(CancellationToken cancellationToken)
var jobName = workItem.GetMetadata("JobName");
var workItemName = workItem.GetMetadata("WorkItemName");
var consoleUri = workItem.GetMetadata("ConsoleOutputUri");
var exitCode = workItem.GetMetadata("ExitCode");
var consoleErrorText = workItem.GetMetadata("ConsoleErrorText");

Log.LogError(FailureCategory.Test, $"Work item {workItemName} in job {jobName} has failed.\nFailure log: {consoleUri}{accessTokenSuffix}");
var sb = new System.Text.StringBuilder();
sb.Append($"Work item {workItemName} in job {jobName} has failed.");

if (!string.IsNullOrEmpty(exitCode))
{
sb.Append($" (exit code {exitCode})");
}

sb.AppendLine();
sb.AppendLine($"Failure log: {consoleUri}{accessTokenSuffix}");

if (!string.IsNullOrEmpty(consoleErrorText))
{
sb.AppendLine();
sb.AppendLine("Error details:");
// Truncate to avoid excessively long MSBuild error messages
string truncated = consoleErrorText.Length > 2000
? consoleErrorText.Substring(0, 2000) + "..."
: consoleErrorText;
sb.Append(truncated);
}

Log.LogError(FailureCategory.Test, sb.ToString());
}
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -26,11 +26,73 @@ protected override async Task ExecuteCoreAsync(HttpClient client)
var testRunId = workItem.GetMetadata("TestRunId");
var failed = workItem.GetMetadata("Failed") == "true";

await CreateFakeTestResultAsync(client, testRunId, jobName, workItemName, failed);
// Build a meaningful error message from available diagnostics
string errorMessage = null;
if (failed)
{
errorMessage = BuildErrorMessage(workItem, jobName, workItemName);
}

await CreateFakeTestResultAsync(client, testRunId, jobName, workItemName, failed, errorMessage);
}
}

private static string BuildErrorMessage(ITaskItem workItem, string jobName, string workItemName)
{
var sb = new StringBuilder();

string exitCode = workItem.GetMetadata("ExitCode");
if (!string.IsNullOrEmpty(exitCode))
{
sb.AppendLine($"Helix work item exited with code {exitCode}.");
}

string helixErrors = workItem.GetMetadata("HelixErrors");
if (!string.IsNullOrEmpty(helixErrors))
{
try
{
var errors = JsonConvert.DeserializeObject<string[]>(helixErrors);
if (errors?.Length > 0)
{
sb.AppendLine("Helix errors:");
foreach (var error in errors)
{
sb.AppendLine($" - {error}");
}
}
}
catch (JsonException)
{
// Ignore deserialization failures
}
}

string consoleErrorText = workItem.GetMetadata("ConsoleErrorText");
if (!string.IsNullOrEmpty(consoleErrorText))
{
sb.AppendLine();
sb.AppendLine("Test output:");
sb.AppendLine(consoleErrorText);
}

if (sb.Length == 0)
{
// Fallback to original generic message if we couldn't extract anything
sb.AppendLine("The Helix Work Item failed. Often this is due to a test crash. Please see the 'Artifacts' tab above for additional logs.");
}

string consoleUri = workItem.GetMetadata("ConsoleOutputUri");
if (!string.IsNullOrEmpty(consoleUri))
{
sb.AppendLine();
sb.AppendLine($"Full console log: {consoleUri}");
}

return sb.ToString().TrimEnd();
}

private async Task<int> CreateFakeTestResultAsync(HttpClient client, string testRunId, string jobName, string workItemFriendlyName, bool failed)
private async Task<int> CreateFakeTestResultAsync(HttpClient client, string testRunId, string jobName, string workItemFriendlyName, bool failed, string errorMessage)
{
var testResultData = await RetryAsync(
async () =>
Expand All @@ -51,7 +113,7 @@ private async Task<int> CreateFakeTestResultAsync(HttpClient client, string test
["testCaseTitle"] = $"{workItemFriendlyName} Work Item",
["outcome"] = failed ? "Failed" : "Passed",
["state"] = "Completed",
["errorMessage"] = failed ? "The Helix Work Item failed. Often this is due to a test crash. Please see the 'Artifacts' tab above for additional logs." : null,
["errorMessage"] = failed ? errorMessage : null,
["durationInMs"] = 60 * 1000, // Use a non-zero duration so that the graphs look better.
["comment"] = new JObject
{
Expand Down
117 changes: 117 additions & 0 deletions src/Microsoft.DotNet.Helix/Sdk/GetHelixWorkItems.cs
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,9 @@
using System.Collections;
using System.Collections.Generic;
using System.Collections.Immutable;
using System.IO;
using System.Linq;
using System.Text;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Build.Framework;
Expand Down Expand Up @@ -113,11 +115,126 @@ ITaskItem2 CreateTaskItem(string workItemName, IDictionary<string, string> metad
Log.LogWarningFromException(ex);
}

// Fetch console output and work item details for failed items so we can surface
// actual error messages instead of the generic "work item failed" text.
try
{
var details = await HelixApi.WorkItem.DetailsAsync(wi, jobName, cancellationToken).ConfigureAwait(false);
if (details.ExitCode.HasValue)
{
metadata["ExitCode"] = details.ExitCode.Value.ToString();
}
if (details.Errors != null && details.Errors.Count > 0)
{
metadata["HelixErrors"] = JsonConvert.SerializeObject(details.Errors.Select(e => e.Message));
}
}
catch (Exception ex)
{
Log.LogMessage(MessageImportance.Low, $"Failed to get work item details for {wi}: {ex.Message}");
}

try
{
using (var consoleStream = await HelixApi.WorkItem.ConsoleLogAsync(wi, jobName, cancellationToken).ConfigureAwait(false))
using (var reader = new StreamReader(consoleStream, Encoding.UTF8))
{
string fullConsole = await reader.ReadToEndAsync().ConfigureAwait(false);
if (!string.IsNullOrEmpty(fullConsole))
{
// Extract the tail of the console output (last ~100 lines) to capture errors near the crash
string[] lines = fullConsole.Split(new[] { '\r', '\n' }, StringSplitOptions.RemoveEmptyEntries);
int startIndex = Math.Max(0, lines.Length - 100);
string tail = string.Join(Environment.NewLine, lines, startIndex, lines.Length - startIndex);

// Also try to extract specific test failure messages from the console output
string errorExcerpt = ExtractTestFailureMessages(fullConsole, tail);
metadata["ConsoleErrorText"] = errorExcerpt;
}
}
}
catch (Exception ex)
{
Log.LogMessage(MessageImportance.Low, $"Failed to fetch console output for {wi}: {ex.Message}");
}

workItems.Add(CreateTaskItem($"{jobName}/{wi}", metadata));
await Task.Delay(DelayBetweenHelixApiCallsInMs, cancellationToken);
}

return workItems;
}

/// <summary>
/// Extracts actionable test failure messages from console output.
/// Looks for common patterns from dotnet test / xUnit / MSTest failure output.
/// Falls back to the tail of the console if no specific patterns are found.
/// </summary>
private static string ExtractTestFailureMessages(string fullConsole, string tail)
{
var sb = new StringBuilder();

// Look for "Failed" test result lines from dotnet test console output
// Pattern: " Failed TestClassName.MethodName [duration]"
string[] allLines = fullConsole.Split(new[] { '\r', '\n' }, StringSplitOptions.RemoveEmptyEntries);

bool inFailureBlock = false;
int failureLineCount = 0;
const int maxFailureLines = 30; // Cap per failure block to avoid giant output
int totalFailuresFound = 0;
const int maxTotalFailures = 5; // Only show first N failures

foreach (string line in allLines)
{
string trimmed = line.TrimStart();

// Detect start of a failure block
if (trimmed.StartsWith("Failed ", StringComparison.OrdinalIgnoreCase) ||
trimmed.StartsWith("Error Message:", StringComparison.OrdinalIgnoreCase) ||
trimmed.StartsWith("Assert.", StringComparison.OrdinalIgnoreCase))
{
if (!inFailureBlock)
{
totalFailuresFound++;
if (totalFailuresFound > maxTotalFailures)
{
sb.AppendLine($"... and more failures (showing first {maxTotalFailures})");
break;
}
inFailureBlock = true;
failureLineCount = 0;
if (sb.Length > 0)
sb.AppendLine();
}
}

if (inFailureBlock)
{
sb.AppendLine(line);
failureLineCount++;

// End the block after enough context or on a blank-ish line after error content
if (failureLineCount >= maxFailureLines ||
(failureLineCount > 3 && string.IsNullOrWhiteSpace(trimmed)))
{
inFailureBlock = false;
}
}
}

// If we found structured failure messages, return them
if (sb.Length > 0)
{
return sb.ToString().TrimEnd();
}

// Otherwise, return the tail of the console output as-is
// Truncate to ~4000 chars to fit in AzDO errorMessage field
if (tail.Length > 4000)
{
tail = "..." + tail.Substring(tail.Length - 4000);
}
return tail;
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -13,8 +13,65 @@ def __no_results_result():
work_item_name = get_env("HELIX_WORKITEM_FRIENDLYNAME")

if exitCode != "0":
# if we have a catastrophic failure, we want to create the fake test result with attached dump files and logs (if available)
return
# Work item crashed / exited non-zero without producing result files.
# Try to capture useful error information from available sources.
failure_message = "Work item exited with code {}. No test result files were produced.".format(exitCode)
attachments = []

# Try to capture console output from the test process
# The stdout/stderr of the test command is available in the work item's console log
# but we can also check for any error output files
upload_root = get_env("HELIX_WORKITEM_UPLOAD_ROOT")
workitem_root = get_env("HELIX_WORKITEM_ROOT")

# Look for blame sequence files that indicate which test was running when crash occurred
error_details = []
for search_dir in [os.getcwd(), upload_root, workitem_root]:
if not search_dir or not os.path.isdir(search_dir):
continue
for root, dirs, files in os.walk(search_dir):
for f in files:
fpath = os.path.join(root, f)
try:
# Blame sequence file tells us which test was running
if f == "Sequence.xml" or f.endswith("_Sequence.xml"):
with open(fpath, 'r', errors='replace') as seq_file:
content = seq_file.read()
error_details.append("Blame sequence (last test running at crash):\n" + content[-2000:])
attachments.append(TestResultAttachment(
name=u"Sequence.xml",
text=content,
))
# Capture any .log files that might have error details
elif f.endswith("TestLog.log") or f == "dotnetTestLog.log":
with open(fpath, 'r', errors='replace') as log_file:
content = log_file.read()
# Get last 3000 chars which likely contain the error
tail = content[-3000:] if len(content) > 3000 else content
error_details.append("Test log tail:\n" + tail)
attachments.append(TestResultAttachment(
name=f,
text=content,
))
except Exception as e:
log.warning("Failed to read {}: {}".format(fpath, e))

if error_details:
failure_message += "\n\n" + "\n\n".join(error_details)

return TestResult(
name=u'{}.WorkItemExecution'.format(work_item_name),
kind=u'unknown',
type_name=u'{}'.format(work_item_name),
method=u'WorkItemExecution',
duration=1,
result=u'Fail',
exception_type=None,
failure_message=failure_message,
stack_trace=None,
skip_reason=None,
attachments=attachments,
)
else:
result = 'Pass'
failure_message = None
Expand Down Expand Up @@ -53,4 +110,6 @@ def read_results(dirs_to_check: List[str]) -> Iterable[TestResult]:

if not found:
log.warn('No results file found in any of the following formats: {}'.format(', '.join((f.name for f in all_formats))))
yield __no_results_result()
result = __no_results_result()
if result is not None:
yield result
Loading