Skip to content

Commit

Permalink
Add Symbolication to XUnitLogChecker (dotnet#83702)
Browse files Browse the repository at this point in the history
  • Loading branch information
ivdiazsa committed Mar 23, 2023
1 parent 4b98c61 commit e83f69a
Show file tree
Hide file tree
Showing 6 changed files with 135 additions and 16 deletions.
4 changes: 2 additions & 2 deletions src/tests/Common/Coreclr.TestWrapper/CoreclrTestWrapperLib.cs
Original file line number Diff line number Diff line change
Expand Up @@ -363,7 +363,7 @@ static bool RunProcess(string fileName, string arguments, TextWriter outputWrite
/// <param name="crashReportJsonFile">crash dump path</param>
/// <param name="outputWriter">Stream for writing logs</param>
/// <returns>true, if we can print the stack trace, otherwise false.</returns>
static bool TryPrintStackTraceFromCrashReport(string crashReportJsonFile, StreamWriter outputWriter)
public static bool TryPrintStackTraceFromCrashReport(string crashReportJsonFile, TextWriter outputWriter)
{
if (OperatingSystem.IsLinux() || OperatingSystem.IsMacOS())
{
Expand Down Expand Up @@ -585,7 +585,7 @@ private static void AppendAddress(StringBuilder sb, string coreRoot, string nati
}
}

static bool TryPrintStackTraceFromDmp(string dmpFile, StreamWriter outputWriter)
public static bool TryPrintStackTraceFromDmp(string dmpFile, TextWriter outputWriter)
{
string targetArchitecture = Environment.GetEnvironmentVariable(TEST_TARGET_ARCHITECTURE_ENVIRONMENT_VAR);
if (string.IsNullOrEmpty(targetArchitecture))
Expand Down
108 changes: 101 additions & 7 deletions src/tests/Common/XUnitLogChecker/XUnitLogChecker.cs
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,9 @@
using System.Text.RegularExpressions;
using System.Threading;
using System.Xml;
using System.Xml.Linq;

using CoreclrTestWrapperLib = CoreclrTestLib.CoreclrTestWrapperLib;

public class XUnitLogChecker
{
Expand Down Expand Up @@ -35,7 +38,6 @@ private enum TagCategory { OPENING, CLOSING }

static int Main(string[] args)
{
// Maybe add a '--help' flag that also gets triggered in this case.
if (args.Length < 2)
{
Console.WriteLine("[XUnitLogChecker]: The path to the log file and"
Expand Down Expand Up @@ -77,9 +79,7 @@ static int Main(string[] args)
}

// If the final results log file is present, then we can assume everything
// went fine, and it's ready to go without any further processing. We just
// check the stats csv file to know how many tests were run, and display a
// brief summary of the work item.
// went fine, and it's ready to go without any further processing.

if (File.Exists(finalLogPath))
{
Expand All @@ -100,9 +100,7 @@ static int Main(string[] args)
return FAILURE;
}

// Declaring the enumerable to contain the log lines first because we
// might not be able to read on the first try due to locked resources
// on Windows. We will retry for up to one minute when this case happens.
// Read the tests run stats csv.
IEnumerable<string>? workItemStats = TryReadFile(statsCsvPath);

if (workItemStats is null)
Expand Down Expand Up @@ -142,14 +140,38 @@ static int Main(string[] args)

PrintWorkItemSummary(numExpectedTests, workItemEndStatus);

// The third command-line argument is an optional path where dumps would
// be located. If passed, then search that path accordingly. Otherwise,
// just skip and finish running.

if (args.Length > 2)
{
string dumpsPath = args[2];

if (Directory.Exists(dumpsPath))
{
PrintStackTracesFromDumps(dumpsPath, tempLogPath);
}
else
{
Console.WriteLine("[XUnitLogChecker]: The provided dumps path"
+ $" '{dumpsPath}' was not able to be read or"
+ " found. Skipping stack traces search...");
}
}

// Rename the temp log to the final log, so that Helix can use it without
// knowing what transpired here.
File.Move(tempLogPath, finalLogPath);
Console.WriteLine("[XUnitLogChecker]: Finished!");
return SUCCESS;
}

static IEnumerable<string> TryReadFile(string filePath)
{
// Declaring the enumerable to contain the log lines first because we
// might not be able to read on the first try due to locked resources
// on Windows. We will retry for up to one minute when this case happens.
IEnumerable<string>? fileContents = null;
Stopwatch fileReadStopwatch = Stopwatch.StartNew();

Expand All @@ -175,6 +197,18 @@ static IEnumerable<string> TryReadFile(string filePath)
return fileContents;
}

static void PrintMissingCrashPath(string wrapperName,
string crashFileType,
string crashFilePath)
{
Console.WriteLine($"[XUnitLogChecker]: Item '{wrapperName}' did not complete"
+ $" successfully, but there was no {crashFileType} found."
+ " The XML log was fixed successfully though.");

Console.WriteLine($"[XUnitLogChecker]: Expected {crashFileType} path"
+ $" was '{crashFilePath}'");
}

static void PrintWorkItemSummary(int numExpectedTests, int[] workItemEndStatus)
{
Console.WriteLine($"\n{workItemEndStatus[0]}/{numExpectedTests} tests run.");
Expand Down Expand Up @@ -347,5 +381,65 @@ static TagResult[] GetOrderedTagMatches(Match[] openingTags, Match[] closingTags
}
return result;
}

static void PrintStackTracesFromDumps(string dumpsPath, string tempLogPath)
{
Console.WriteLine("[XUnitLogChecker]: Checking for dumps...");

// Read our newly fixed log to retrieve the time and date when the
// test was run. This is to exclude potentially existing older dumps
// that are not related to this test run.
XElement fixedLogTree = XElement.Load(tempLogPath);

// We know from the XUnitWrapperGenerator that the top element
// is the 'assembly' tag we're looking for.
var testRunDateTime = DateTime.ParseExact
(
fixedLogTree.Attribute("run-date-time").Value,
"yyyy-MM-dd HH:mm:ss",
System.Globalization.CultureInfo.InvariantCulture
);

IEnumerable<string> dumpsFound =
Directory.GetFiles(dumpsPath, "*coredump*.dmp")
.Where(dmp => DateTime.Compare(File.GetCreationTime(dmp), testRunDateTime) >= 0);

if (dumpsFound.Count() == 0)
{
Console.WriteLine("[XUnitLogChecker]: No crash dumps found. Continuing...");
return ;
}

foreach (string dumpPath in dumpsFound)
{
if (OperatingSystem.IsWindows())
{
Console.WriteLine("[XUnitLogChecker]: Reading crash dump"
+ $" '{dumpPath}'...");
Console.WriteLine("[XUnitLogChecker]: Stack Trace Found:\n");

CoreclrTestWrapperLib.TryPrintStackTraceFromDmp(dumpPath,
Console.Out);
}
else
{
string crashReportPath = $"{dumpPath}.crashreport.json";

if (!File.Exists(crashReportPath))
{
Console.WriteLine("[XUnitLogChecker]: There was no crash"
+ $" report for dump '{dumpPath}'. Skipping...");
continue;
}

Console.WriteLine("[XUnitLogChecker]: Reading crash report"
+ $" '{crashReportPath}'...");
Console.WriteLine("[XUnitLogChecker]: Stack Trace Found:\n");

CoreclrTestWrapperLib.TryPrintStackTraceFromCrashReport(crashReportPath,
Console.Out);
}
}
}
}

5 changes: 5 additions & 0 deletions src/tests/Common/XUnitLogChecker/XUnitLogChecker.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,15 @@
<OutputType>Exe</OutputType>
<TargetFramework>$(NetCoreAppToolCurrent)</TargetFramework>
<GenerateRuntimeConfigurationFiles>true</GenerateRuntimeConfigurationFiles>
<AllowUnsafeBlocks>true</AllowUnsafeBlocks>
</PropertyGroup>

<ItemGroup>
<Compile Include="XUnitLogChecker.cs" />
</ItemGroup>

<ItemGroup>
<Compile Include="../Coreclr.TestWrapper/CoreclrTestWrapperLib.cs" Link="CoreclrTestWrapperLib.cs" />
<Compile Include="../Coreclr.TestWrapper/MobileAppHandler.cs" Link="MobileAppHandler.cs" />
</ItemGroup>
</Project>
11 changes: 8 additions & 3 deletions src/tests/Common/XUnitWrapperGenerator/XUnitWrapperGenerator.cs
Original file line number Diff line number Diff line change
Expand Up @@ -182,22 +182,24 @@ private static string GenerateFullTestRunner(ImmutableArray<ITestInfo> testInfos
builder.AppendLine();

builder.AppendLine("XUnitWrapperLibrary.TestFilter filter = new (args, testExclusionList);");
// builder.AppendLine("XUnitWrapperLibrary.TestSummary summary = new(TestCount.Count);");
builder.AppendLine("XUnitWrapperLibrary.TestSummary summary = new();");
builder.AppendLine("System.Diagnostics.Stopwatch stopwatch = System.Diagnostics.Stopwatch.StartNew();");
builder.AppendLine("XUnitWrapperLibrary.TestOutputRecorder outputRecorder = new(System.Console.Out);");
builder.AppendLine("System.Console.SetOut(outputRecorder);");
builder.AppendLine();

builder.AppendLine($@"using (System.IO.StreamWriter tempLogSw = System.IO.File.AppendText(""{assemblyName}.tempLog.xml""))");
builder.AppendLine($@"using (System.IO.StreamWriter statsCsvSw = System.IO.File.AppendText(""{assemblyName}.testStats.csv""))");

builder.AppendLine($@"using (System.IO.StreamWriter statsCsvSw = System.IO.File.AppendText(""{assemblyName}.testStats.csv"")){{");
CodeBuilder testExecutorBuilder = new();
int totalTestsEmitted = 0;

using (builder.NewBracesScope())
{
builder.AppendLine("statsCsvSw.WriteLine($\"{TestCount.Count},0,0,0\");");
// CAUTION NOTE: If this ever changes and the 'assembly' tag is no longer
// the topmost one in the temp log, XUnitLogChecker must be updated accordingly.
// Otherwise, it's going to fail when attempting to find dumps.
builder.AppendLine($@"summary.WriteHeaderToTempLog(""{assemblyName}"", tempLogSw);");

ITestReporterWrapper reporter =
new WrapperLibraryTestSummaryReporting("summary", "filter", "outputRecorder");
Expand Down Expand Up @@ -243,6 +245,9 @@ private static string GenerateFullTestRunner(ImmutableArray<ITestInfo> testInfos
testExecutorBuilder.AppendLine("}");
testExecutorBuilder.AppendLine();
}

testExecutorBuilder.AppendLine("}");
builder.AppendLine("tempLogSw.WriteLine(\"</assembly>\");");
}
builder.AppendLine();

Expand Down
12 changes: 11 additions & 1 deletion src/tests/Common/XUnitWrapperLibrary/TestSummary.cs
Original file line number Diff line number Diff line change
Expand Up @@ -104,6 +104,16 @@ public string ToXmlString()
private readonly List<TestResult> _testResults = new();
private DateTime _testRunStart = DateTime.Now;

public void WriteHeaderToTempLog(string assemblyName, StreamWriter tempLogSw)
{
// We are writing down both, date and time, in the same field here because
// it's much simpler to parse later on in the XUnitLogChecker.
tempLogSw.WriteLine("<assembly\n"
+ $" name=\"{assemblyName}\"\n"
+ $" test-framework=\"XUnitWrapperGenerator-generated-runner\"\n"
+ $" run-date-time=\"{_testRunStart.ToString("yyyy-MM-dd HH:mm:ss")}\">");
}

public void ReportPassedTest(string name,
string containingTypeName,
string methodName,
Expand Down Expand Up @@ -174,7 +184,7 @@ public string GetTestResultOutput(string assemblyName)
name=""{assemblyName}""
test-framework=""XUnitWrapperGenerator-generated-runner""
run-date=""{_testRunStart.ToString("yyyy-MM-dd")}""
run-time=""{_testRunStart.ToString("hh:mm:ss")}""
run-time=""{_testRunStart.ToString("HH:mm:ss")}""
time=""{totalRunSeconds}""
total=""{_testResults.Count}""
passed=""{PassedTests}""
Expand Down
11 changes: 8 additions & 3 deletions src/tests/Common/helixpublishwitharcade.proj
Original file line number Diff line number Diff line change
Expand Up @@ -400,9 +400,14 @@
</ItemGroup>

<PropertyGroup>
<XUnitLogCheckerCommand Condition="'$(TestWrapperTargetsWindows)' != 'true'">dotnet %24HELIX_CORRELATION_PAYLOAD/XUnitLogChecker/</XUnitLogCheckerCommand>
<XUnitLogCheckerCommand Condition="'$(TestWrapperTargetsWindows)' == 'true'">dotnet %25HELIX_CORRELATION_PAYLOAD%25/XUnitLogChecker/</XUnitLogCheckerCommand>
<XUnitLogCheckerCommand>$(XUnitLogCheckerCommand)XUnitLogChecker.dll $(_MergedWrapperRunScriptDirectoryRelative) $(_MergedWrapperName)</XUnitLogCheckerCommand>
<XUnitLogCheckerHelixPath Condition="'$(TestWrapperTargetsWindows)' != 'true'">%24HELIX_CORRELATION_PAYLOAD/</XUnitLogCheckerHelixPath>
<XUnitLogCheckerHelixPath Condition="'$(TestWrapperTargetsWindows)' == 'true'">%25HELIX_CORRELATION_PAYLOAD%25/</XUnitLogCheckerHelixPath>
<XUnitLogCheckerHelixPath>$(XUnitLogCheckerHelixPath)XUnitLogChecker/</XUnitLogCheckerHelixPath>

<XUnitLogCheckerArgs>$(_MergedWrapperRunScriptDirectoryRelative) $(_MergedWrapperName)</XUnitLogCheckerArgs>
<XUnitLogCheckerArgs Condition="'$(TestWrapperTargetsWindows)' != 'true'">$(XUnitLogCheckerArgs) %24HELIX_DUMP_FOLDER</XUnitLogCheckerArgs>
<XUnitLogCheckerArgs Condition="'$(TestWrapperTargetsWindows)' == 'true'">$(XUnitLogCheckerArgs) %25HELIX_DUMP_FOLDER%25</XUnitLogCheckerArgs>
<XUnitLogCheckerCommand>dotnet $(XUnitLogCheckerHelixPath)XUnitLogChecker.dll $(XUnitLogCheckerArgs)</XUnitLogCheckerCommand>
</PropertyGroup>

<ItemGroup>
Expand Down

0 comments on commit e83f69a

Please sign in to comment.