Mesa (main): ci/lava: Stop printing after the result line

[GitLab Mirror]

Module: Mesa
Branch: main
Commit: 24f368d652d93abec3b0e3ddcf1ea83f1214f199
URL:    http://cgit.freedesktop.org/mesa/mesa/commit/?id=24f368d652d93abec3b0e3ddcf1ea83f1214f199

Author: Guilherme Gallo <guilherme.gallo at collabora.com>
Date:   Thu Jun 30 19:46:40 2022 -0300

ci/lava: Stop printing after the result line

There are some leftovers in the jobs logs after the result log line.
Only print until the init-stage2.sh output, to raise the chance to check
for the test script results at the first glance in the Gitlab logs.

Extra changes:
- Add `hung` status for jobs considered hanging in the Gitlab
- print them after the retry loop

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

---

 .gitlab-ci/lava/lava_job_submitter.py       | 42 +++++++++++++++++------------
 .gitlab-ci/tests/test_lava_job_submitter.py | 22 ++++-----------
 2 files changed, 30 insertions(+), 34 deletions(-)

diff --git a/.gitlab-ci/lava/lava_job_submitter.py b/.gitlab-ci/lava/lava_job_submitter.py
index 7fb44969b7b..88332303513 100755
--- a/.gitlab-ci/lava/lava_job_submitter.py
+++ b/.gitlab-ci/lava/lava_job_submitter.py
@@ -294,28 +294,23 @@ class LAVAJob:
                 f"Could not get LAVA job logs. Reason: {mesa_ci_err}"
             ) from mesa_ci_err
 
-    def parse_job_result_from_log(self, lava_lines: list[dict[str, str]]) -> None:
+    def parse_job_result_from_log(
+        self, lava_lines: list[dict[str, str]]
+    ) -> list[dict[str, str]]:
         """Use the console log to catch if the job has completed successfully or
-        not.
-        Returns true only the job finished by looking into the log result
-        parsing.
-        """
-        log_lines = [l["msg"] for l in lava_lines if l["lvl"] == "target"]
-        for line in log_lines:
+        not. Returns the list of log lines until the result line."""
+
+        last_line = None  # Print all lines. lines[:None] == lines[:]
+
+        for idx, line in enumerate(lava_lines):
             if result := re.search(r"hwci: mesa: (pass|fail)", line):
                 self.is_finished = True
                 self.status = result.group(1)
-                color = LAVAJob.COLOR_STATUS_MAP.get(
-                    self.status, CONSOLE_LOG["COLOR_RED"]
-                )
-                print_log(
-                    f"{color}"
-                    f"LAVA Job finished with result: {self.status}"
-                    f"{CONSOLE_LOG['RESET']}"
-                )
 
+                last_line = idx + 1
                 # We reached the log end here. hwci script has finished.
                 break
+        return lava_lines[:last_line]
 
 
 def find_exception_from_metadata(metadata, job_id):
@@ -403,11 +398,11 @@ def fetch_logs(job, max_idle_time, log_follower) -> None:
         job.heartbeat()
     parsed_lines = log_follower.flush()
 
+    parsed_lines = job.parse_job_result_from_log(parsed_lines)
+
     for line in parsed_lines:
         print_log(line)
 
-    job.parse_job_result_from_log(new_log_lines)
-
 
 def follow_job_execution(job):
     try:
@@ -447,6 +442,18 @@ def follow_job_execution(job):
         find_lava_error(job)
 
 
+def print_job_final_status(job):
+    if job.status == "running":
+        job.status = "hung"
+
+    color = LAVAJob.COLOR_STATUS_MAP.get(job.status, CONSOLE_LOG["COLOR_RED"])
+    print_log(
+        f"{color}"
+        f"LAVA Job finished with status: {job.status}"
+        f"{CONSOLE_LOG['RESET']}"
+    )
+
+
 def retriable_follow_job(proxy, job_definition) -> LAVAJob:
     retry_count = NUMBER_OF_RETRIES_TIMEOUT_DETECTION
 
@@ -464,6 +471,7 @@ def retriable_follow_job(proxy, job_definition) -> LAVAJob:
             raise e
         finally:
             print_log(f"Finished executing LAVA job in the attempt #{attempt_no}")
+            print_job_final_status(job)
 
     raise MesaCIRetryError(
         "Job failed after it exceeded the number of " f"{retry_count} retries.",
diff --git a/.gitlab-ci/tests/test_lava_job_submitter.py b/.gitlab-ci/tests/test_lava_job_submitter.py
index 482de6dd5c4..30760c4ddf4 100644
--- a/.gitlab-ci/tests/test_lava_job_submitter.py
+++ b/.gitlab-ci/tests/test_lava_job_submitter.py
@@ -259,34 +259,22 @@ def test_log_corruption(mock_sleep, data_sequence, expected_exception, mock_prox
 LAVA_RESULT_LOG_SCENARIOS = {
     # the submitter should accept xtrace logs
     "Bash xtrace echo with kmsg interleaving": (
-        create_lava_yaml_msg(
-            msg="echo hwci: mesa: pass[  737.673352] <LAVA_SIGNAL_ENDTC mesa-ci>",
-            lvl="target",
-        ),
+        "echo hwci: mesa: pass[  737.673352] <LAVA_SIGNAL_ENDTC mesa-ci>",
         "pass",
     ),
     # the submitter should accept xtrace logs
     "kmsg result print": (
-        create_lava_yaml_msg(
-            msg="[  737.673352] hwci: mesa: pass",
-            lvl="target",
-        ),
+        "[  737.673352] hwci: mesa: pass",
         "pass",
     ),
     # if the job result echo has a very bad luck, it still can be interleaved
     # with kmsg
     "echo output with kmsg interleaving": (
-        create_lava_yaml_msg(
-            msg="hwci: mesa: pass[  737.673352] <LAVA_SIGNAL_ENDTC mesa-ci>",
-            lvl="target",
-        ),
+        "hwci: mesa: pass[  737.673352] <LAVA_SIGNAL_ENDTC mesa-ci>",
         "pass",
     ),
     "fail case": (
-        create_lava_yaml_msg(
-            msg="hwci: mesa: fail",
-            lvl="target",
-        ),
+        "hwci: mesa: fail",
         "fail",
     ),
 }
@@ -297,7 +285,7 @@ LAVA_RESULT_LOG_SCENARIOS = {
     LAVA_RESULT_LOG_SCENARIOS.values(),
     ids=LAVA_RESULT_LOG_SCENARIOS.keys(),
 )
-def test_filter_debug_messages(message, expectation, mock_proxy):
+def test_parse_job_result_from_log(message, expectation, mock_proxy):
     job = LAVAJob(mock_proxy(), "")
     job.parse_job_result_from_log([message])