ci/lava: Flexibilize section marker regexes

In some jobs, such as
https://gitlab.freedesktop.org/gallo/mesa/-/jobs/24904100, the kmsg is
interleaved with stderr/stdout in serial console, making it difficult to
confidently find the log messages to detect when the DUT is booting,
when the DUT is running etc.

Luckily, LAVA sends redundant messages about their signals. We can use
them to mitigate the chance of missing an interleaved message by being
more open to different messages, using the regex on both `debug` and
`target` LAVA log levels.

Signed-off-by: Guilherme Gallo <guilherme.gallo@collabora.com>
Part-of: <https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/16323>

diff --git a/.gitlab-ci/lava/utils/lava_log.py b/.gitlab-ci/lava/utils/lava_log.py
index 090c965..36b2979 100644 (file)
--- a/.gitlab-ci/lava/utils/lava_log.py
+++ b/.gitlab-ci/lava/utils/lava_log.py
@@ -145,7 +145,7 @@ class GitlabSection:
 @dataclass(frozen=True)
 class LogSection:
     regex: Union[Pattern, str]
-    level: str
+    levels: tuple[str]
     section_id: str
     section_header: str
     section_type: LogSectionType
@@ -154,36 +154,38 @@ class LogSection:
     def from_log_line_to_section(
         self, lava_log_line: dict[str, str]
     ) -> Optional[GitlabSection]:
-        if lava_log_line["lvl"] == self.level:
-            if match := re.match(self.regex, lava_log_line["msg"]):
-                section_id = self.section_id.format(*match.groups())
-                section_header = self.section_header.format(*match.groups())
-                return GitlabSection(
-                    id=section_id,
-                    header=section_header,
-                    type=self.section_type,
-                    start_collapsed=self.collapsed,
-                )
+        if lava_log_line["lvl"] not in self.levels:
+            return
+
+        if match := re.search(self.regex, lava_log_line["msg"]):
+            section_id = self.section_id.format(*match.groups())
+            section_header = self.section_header.format(*match.groups())
+            return GitlabSection(
+                id=section_id,
+                header=section_header,
+                type=self.section_type,
+                start_collapsed=self.collapsed,
+            )
 
 
 LOG_SECTIONS = (
     LogSection(
-        regex=re.compile(r".*<STARTTC> (.*)"),
-        level="debug",
+        regex=re.compile(r"<?STARTTC>? ([^>]*)"),
+        levels=("target", "debug"),
         section_id="{}",
         section_header="test_case {}",
         section_type=LogSectionType.TEST_CASE,
     ),
     LogSection(
-        regex=re.compile(r".*<STARTRUN> (\S*)"),
-        level="debug",
+        regex=re.compile(r"<?STARTRUN>? ([^>]*)"),
+        levels=("target", "debug"),
         section_id="{}",
         section_header="test_suite {}",
         section_type=LogSectionType.TEST_SUITE,
     ),
     LogSection(
-        regex=re.compile(r"^<LAVA_SIGNAL_ENDTC ([^>]+)"),
-        level="target",
+        regex=re.compile(r"ENDTC>? ([^>]+)"),
+        levels=("target", "debug"),
         section_id="post-{}",
         section_header="Post test_case {}",
         collapsed=True,
@@ -208,7 +210,7 @@ class LogFollower:
         )
         assert (
             section_is_created == section_has_started
-        ), "Can't follow logs beginning from uninitalized GitLab sections."
+        ), "Can't follow logs beginning from uninitialized GitLab sections."
 
     def __enter__(self):
         return self
@@ -240,6 +242,10 @@ class LogFollower:
             self.current_section = None
 
     def update_section(self, new_section: GitlabSection):
+        # Sections can have redundant regex to find them to mitigate LAVA
+        # interleaving kmsg and stderr/stdout issue.
+        if self.current_section and self.current_section.id == new_section.id:
+            return
         self.clear_current_section()
         self.current_section = new_section
         self._buffer.append(new_section.start())

diff --git a/.gitlab-ci/tests/utils/test_lava_log.py b/.gitlab-ci/tests/utils/test_lava_log.py
index 32325c9..24e46ff 100644 (file)
--- a/.gitlab-ci/tests/utils/test_lava_log.py
+++ b/.gitlab-ci/tests/utils/test_lava_log.py
@@ -86,11 +86,24 @@ def test_gl_sections():
             "lvl": "debug",
             "msg": "Received signal: <STARTRUN> 0_mesa 5971831_1.3.2.3.1",
         },
+        # Redundant log message which triggers the same Gitlab Section, it
+        # should be ignored, unless the id is different
+        {
+            "dt": datetime.now(),
+            "lvl": "target",
+            "msg": "[    7.778836] <LAVA_SIGNAL_STARTRUN 0_mesa 5971831_1.3.2.3.1>",
+        },
         {
             "dt": datetime.now(),
             "lvl": "debug",
             "msg": "Received signal: <STARTTC> mesa-ci_iris-kbl-traces",
         },
+        # Another redundant log message
+        {
+            "dt": datetime.now(),
+            "lvl": "target",
+            "msg": "[   16.997829] <LAVA_SIGNAL_STARTTC mesa-ci_iris-kbl-traces>",
+        },
         {
             "dt": datetime.now(),
             "lvl": "target",