From 02b8071c7212f409384c153c62f85a00b05edfb1 Mon Sep 17 00:00:00 2001
From: Ivan Diaz Sanchez <ivdiazsa@microsoft.com>
Date: Fri, 28 Apr 2023 13:39:49 -0700
Subject: [PATCH] Fix XUnit Log Fixer Irregularities (#85183)

* Fixed the log tags regular expressions.

* Added test exit code to the XUnit Log Checker, and made it return it as well for Helix to process it.

* Finished fixes.

* Decoupled the test's exit code from the XUnit Log Checker.
---
 .../Common/XUnitLogChecker/XUnitLogChecker.cs      | 67 ++++++++++------------
 src/tests/Common/helixpublishwitharcade.proj       | 25 ++++++++
 2 files changed, 56 insertions(+), 36 deletions(-)

diff --git a/src/tests/Common/XUnitLogChecker/XUnitLogChecker.cs b/src/tests/Common/XUnitLogChecker/XUnitLogChecker.cs
index a92ca94..5fb17cc 100644
--- a/src/tests/Common/XUnitLogChecker/XUnitLogChecker.cs
+++ b/src/tests/Common/XUnitLogChecker/XUnitLogChecker.cs
@@ -14,8 +14,8 @@ public class XUnitLogChecker
 {
     private static class Patterns
     {
-        public const string OpenTag = @"(\B<\w+)|(\B<!\[CDATA\[)";
-        public const string CloseTag = @"(\B</\w+>)|(\]\]>)";
+        public const string OpenTag = @"(\B<\w+[-]?(\w+)?)|(\B<!\[CDATA\[)";
+        public const string CloseTag = @"(\B</\w+[-]?(\w+)?)|(\]\]>)";
     }
 
     private readonly struct TagResult
@@ -59,6 +59,16 @@ public class XUnitLogChecker
         string finalLogPath = Path.Combine(resultsDir, finalLogName);
         string statsCsvPath = Path.Combine(resultsDir, statsCsvName);
 
+        // 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.
+
+        if (File.Exists(finalLogPath))
+        {
+            Console.WriteLine($"[XUnitLogChecker]: Item '{wrapperName}' did"
+                              + " complete successfully!");
+            return SUCCESS;
+        }
+
         // If there are no logs, then this work item was probably entirely skipped.
         // This can happen under certain specific circumstances, such as with the
         // JIT Hardware Intrinsics tests with DOTNET_GCStress enabled. See Github
@@ -78,16 +88,6 @@ public class XUnitLogChecker
             return SUCCESS;
         }
 
-        // 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.
-
-        if (File.Exists(finalLogPath))
-        {
-            Console.WriteLine($"[XUnitLogChecker]: Item '{wrapperName}' did"
-                              + " complete successfully!");
-            return SUCCESS;
-        }
-
         // If we're here, then that means we've got something to fix.
         // First, read the stats csv file. If it doesn't exist, then we can
         // assume something went very badly and will likely cause more issues
@@ -197,18 +197,6 @@ public class XUnitLogChecker
         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.");
@@ -255,12 +243,21 @@ public class XUnitLogChecker
                     // We are beginning to process a test's output. Set the flag to
                     // treat everything as such, until we get the closing output tag.
                     if (tagText.Equals("output") && !inOutput && !inCData)
+                    {
                         inOutput = true;
+                    }
                     else if (tagText.Equals("CDATA") && !inCData)
+                    {
                         inCData = true;
+                        tags.Push(tagText);
+                        continue;
+                    }
 
-                    tags.Push(tagText);
-                    continue;
+                    // CDATA tags store plain output, which can include tag-like
+                    // looking strings. So, we skip those until we're done processing
+                    // the current CDATA tag.
+                    if (!inCData)
+                        tags.Push(tagText);
                 }
 
                 // Found a closing tag. If we're currently in an output state, then
@@ -280,28 +277,26 @@ public class XUnitLogChecker
 
                     if (inCData)
                     {
-                        if (tagText.Equals("CDATA"))
+                        if (tagText.Equals("CDATA") && tagText.Equals(tags.Peek()))
                         {
                             tags.Pop();
                             inCData = false;
                         }
-                        else continue;
+                        continue;
                     }
 
                     if (inOutput)
                     {
-                         if (tagText.Equals("output"))
-                         {
-                             tags.Pop();
-                             inOutput = false;
-                         }
-                         else continue;
+                        if (tagText.Equals("output") && tagText.Equals(tags.Peek()))
+                        {
+                            tags.Pop();
+                            inOutput = false;
+                        }
+                        continue;
                     }
 
                     if (tagText.Equals(tags.Peek()))
-                    {
                         tags.Pop();
-                    }
                 }
             }
         }
diff --git a/src/tests/Common/helixpublishwitharcade.proj b/src/tests/Common/helixpublishwitharcade.proj
index 08272b0..25ad139 100644
--- a/src/tests/Common/helixpublishwitharcade.proj
+++ b/src/tests/Common/helixpublishwitharcade.proj
@@ -428,10 +428,35 @@
       <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' == 'true'" Include="set TEST_HARNESS_STRIPE_TO_EXECUTE=.0.1" />
       <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' != 'true'" Include="export TEST_HARNESS_STRIPE_TO_EXECUTE=.0.1" />
       <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' != 'true'" Include="chmod +x $(_MergedWrapperRunScriptRelative)" />
+
       <!-- Force assemblies to lazy-load for LLVM AOT test runs to enable using tests that fail at AOT time (and as a result can't be AOTd) -->
       <HelixCommandLines Condition="'$(RuntimeVariant)' == 'llvmfullaot'" Include="$(_MergedWrapperRunScriptPrefix)$(_MergedWrapperRunScriptRelative) -usewatcher --aot-lazy-assembly-load" />
       <HelixCommandLines Condition="'$(RuntimeVariant)' != 'llvmfullaot'" Include="$(_MergedWrapperRunScriptPrefix)$(_MergedWrapperRunScriptRelative) -usewatcher" />
+
+      <!--
+        Bug Fix: GH Issue #85056 - Helix takes the exit code of the last ran executable. Since that spot has now been
+        taken by the log fixer, its exit code gets reported to Helix, and thus eclipsing the test's one. This might
+        lead to test failures being identified as passed if the log checker finishes successfully. To fix this, we
+        store the test's exit code, and if it's not successful, then we return it after the log checker finishes.
+      -->
+      <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' == 'true'" Include="set test_exit_code=%25ERRORLEVEL%25" />
+      <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' != 'true'" Include="test_exit_code=%24%3F" />
+
+      <!-- Add the XUnitLogChecker's running command and store its exit code. -->
       <HelixCommandLines Include="$(XUnitLogCheckerCommand)" />
+      <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' == 'true'" Include="set xunitlogchecker_exit_code=%25ERRORLEVEL%25" />
+      <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' != 'true'" Include="xunitlogchecker_exit_code=%24%3F" />
+
+      <!--
+        Check both exit codes, the test's and XUnitLogChecker's. If any of them failed, then we return that one, with the
+        test's taking priority (i.e. if the test failed, we return that one regardless of how things went with the log checker.
+        Full description in the reasoning of this is in the comment above about GH issue #85056.
+      -->
+      <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' == 'true'" Include="if %25test_exit_code%25 NEQ 0 exit %25test_exit_code%25" />
+      <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' != 'true'" Include="if [ %24test_exit_code -ne 0 ]%3B then exit %24test_exit_code%3B fi" />
+      <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' == 'true'" Include="if %25xunitlogchecker_exit_code%25 NEQ 0 exit %25xunitlogchecker_exit_code%25" />
+      <HelixCommandLines Condition="'$(TestWrapperTargetsWindows)' != 'true'" Include="if [ %24xunitlogchecker_exit_code -ne 0 ]%3B then exit %24xunitlogchecker_exit_code%3B fi" />
+      <HelixCommandLines Include="exit 0" />
     </ItemGroup>
 
     <Copy SourceFiles="@(ReducedMergedPayloadFilesFinal)" DestinationFiles="@(ReducedMergedPayloadFilesFinal->'$(MergedPayloadsRootDirectory)\$(_MergedWrapperName)\%(FileRelativeToPayloadsRootDirectory)')" Condition="'@(ReducedMergedPayloadFilesFinal)' != ''" />
-- 
2.7.4