ci/hw: Wrap pre-test setup in collapsed section

Most people don't care about environment variables and starting Weston.

Signed-off-by: Daniel Stone <daniels@collabora.com>
Part-of: <https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/31602>

.gitlab-ci/common/init-stage2.sh

@@ -47,6 +47,13 @@ for path in '/dut-env-vars.sh' '/set-job-env-vars.sh' './set-job-env-vars.sh'; d
 done
 . "$SCRIPTS_DIR"/setup-test-env.sh
 
+# Flush out anything which might be stuck in a serial buffer
+echo
+echo
+echo
+
+section_switch init_stage2 "Pre-testing hardware setup"
+
 set -ex
 
 # Set up any devices required by the jobs
@@ -200,6 +207,8 @@ if [ -n "$HWCI_START_WESTON" ]; then
   while [ ! -S "$WESTON_X11_SOCK" ]; do sleep 1; done
 fi
 
+section_end init_stage2
+
 set +e
 $HWCI_TEST_SCRIPT ${HWCI_TEST_ARGS:-}
 EXIT_CODE=$?

.gitlab-ci/lava/lava_job_submitter.py

@@ -252,15 +252,16 @@ def wait_for_job_get_started(job, attempt_no):
     print_log(f"Job {job.job_id} started.")
 
 
-def bootstrap_log_follower() -> LogFollower:
+def bootstrap_log_follower(main_test_case) -> LogFollower:
     start_section = GitlabSection(
         id="dut_boot",
         header="Booting hardware device",
         type=LogSectionType.LAVA_BOOT,
         start_collapsed=True,
+        suppress_end=True, # init-stage2 prints the end for us
     )
     print(start_section.start())
-    return LogFollower(starting_section=start_section)
+    return LogFollower(starting_section=start_section, main_test_case=main_test_case)
 
 
 def follow_job_execution(job, log_follower):
@@ -309,7 +310,7 @@ def print_job_final_status(job):
 
 
 def execute_job_with_retries(
-    proxy, job_definition, retry_count, jobs_log
+    proxy, job_definition, retry_count, jobs_log, main_test_case
 ) -> Optional[LAVAJob]:
     last_failed_job = None
     for attempt_no in range(1, retry_count + 2):
@@ -330,7 +331,7 @@ def execute_job_with_retries(
             )
             with queue_section as section:
                 wait_for_job_get_started(job, attempt_no)
-            log_follower: LogFollower = bootstrap_log_follower()
+            log_follower: LogFollower = bootstrap_log_follower(main_test_case)
             follow_job_execution(job, log_follower)
             return job
 
@@ -354,11 +355,12 @@ def execute_job_with_retries(
     return last_failed_job
 
 
-def retriable_follow_job(proxy, job_definition) -> LAVAJob:
+def retriable_follow_job(proxy, job_definition, main_test_case) -> LAVAJob:
     number_of_retries = NUMBER_OF_RETRIES_TIMEOUT_DETECTION
 
     last_attempted_job = execute_job_with_retries(
-        proxy, job_definition, number_of_retries, STRUCTURAL_LOG["dut_jobs"]
+        proxy, job_definition, number_of_retries, STRUCTURAL_LOG["dut_jobs"],
+        main_test_case
     )
 
     if last_attempted_job.exception is not None:
@@ -488,7 +490,9 @@ class LAVAJobSubmitter(PathResolver):
         with self.__structured_log_context:
             last_attempt_job = None
             try:
-                last_attempt_job = retriable_follow_job(self.proxy, job_definition)
+                last_attempt_job = retriable_follow_job(
+                    self.proxy, job_definition,
+                    f'{self.project_name}_{self.mesa_job_name}')
 
             except MesaCIRetryError as retry_exception:
                 last_attempt_job = retry_exception.last_job

.gitlab-ci/lava/utils/gitlab_section.py

@@ -18,6 +18,8 @@ class GitlabSection:
     header: str
     type: LogSectionType
     start_collapsed: bool = False
+    suppress_end: bool = False
+    suppress_start: bool = False
     escape: str = "\x1b[0K"
     colour: str = f"{CONSOLE_LOG['FG_CYAN']}"
     __start_time: Optional[datetime] = field(default=None, init=False)
@@ -86,6 +88,8 @@ class GitlabSection:
         return self.print_start_section()
 
     def print_start_section(self) -> str:
+        if self.suppress_start:
+            return ""
         return self.section(marker="start", header=self.header, time=self.__start_time)
 
     def end(self) -> str:
@@ -97,6 +101,8 @@ class GitlabSection:
         return self.print_end_section()
 
     def print_end_section(self) -> str:
+        if self.suppress_end:
+            return ""
         return self.section(marker="end", header="", time=self.__end_time)
 
     def delta_time(self) -> Optional[timedelta]:

.gitlab-ci/lava/utils/lava_job_definition.py

@@ -232,4 +232,6 @@ class LAVAJobDefinition:
                 + '-o "/lib/firmware/qcom/sm8350/a660_zap.mbn"'
             )
 
+        run_steps.append("export CURRENT_SECTION=dut_boot")
+
         return run_steps

.gitlab-ci/lava/utils/log_follower.py

@@ -33,6 +33,7 @@ from lava.utils.log_section import (
 @dataclass
 class LogFollower:
     starting_section: Optional[GitlabSection] = None
+    main_test_case: Optional[str] = None
     _current_section: Optional[GitlabSection] = None
     section_history: list[GitlabSection] = field(default_factory=list, init=False)
     timeout_durations: dict[LogSectionType, timedelta] = field(
@@ -122,7 +123,9 @@ class LogFollower:
             return
 
         for log_section in LOG_SECTIONS:
-            if new_section := log_section.from_log_line_to_section(line):
+            if new_section := log_section.from_log_line_to_section(
+                line, self.main_test_case
+            ):
                 self.update_section(new_section)
                 break
 

.gitlab-ci/lava/utils/log_section.py

@@ -75,7 +75,7 @@ class LogSection:
     collapsed: bool = False
 
     def from_log_line_to_section(
-        self, lava_log_line: dict[str, str]
+        self, lava_log_line: dict[str, str], main_test_case: Optional[str]
     ) -> Optional[GitlabSection]:
         if lava_log_line["lvl"] not in self.levels:
             return
@@ -83,12 +83,15 @@ class LogSection:
         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())
+            is_main_test_case = section_id == main_test_case
             timeout = DEFAULT_GITLAB_SECTION_TIMEOUTS[self.section_type]
             return GitlabSection(
                 id=section_id,
                 header=f"{section_header} - Timeout: {timeout}",
                 type=self.section_type,
                 start_collapsed=self.collapsed,
+                suppress_start=is_main_test_case,
+                suppress_end=is_main_test_case,
             )
 
 

.gitlab-ci/tests/data/FASTBOOT_force_uart=False_job_definition.yaml

@@ -86,6 +86,7 @@ actions:
           steps:
           - |-
             echo test FASTBOOT
+            export CURRENT_SECTION=dut_boot
           - export -p > /dut-env-vars.sh
 - test:
     namespace: container

.gitlab-ci/tests/data/FASTBOOT_force_uart=True_job_definition.yaml

@@ -82,6 +82,7 @@ actions:
         run:
           steps:
           - echo test FASTBOOT
+          - export CURRENT_SECTION=dut_boot
           - set -ex
           - curl -L --retry 4 -f --retry-all-errors --retry-delay 60 None | tar -xz
             -C /

.gitlab-ci/tests/data/UBOOT_force_uart=False_job_definition.yaml

@@ -58,6 +58,7 @@ actions:
           steps:
           - |-
             echo test UBOOT
+            export CURRENT_SECTION=dut_boot
           - export -p > /dut-env-vars.sh
 - test:
     namespace: container

.gitlab-ci/tests/data/UBOOT_force_uart=True_job_definition.yaml

@@ -56,6 +56,7 @@ actions:
         run:
           steps:
           - echo test UBOOT
+          - export CURRENT_SECTION=dut_boot
           - set -ex
           - curl -L --retry 4 -f --retry-all-errors --retry-delay 60 None | tar -xz
             -C /

.gitlab-ci/tests/test_lava_job_submitter.py

@@ -86,7 +86,7 @@ def test_submit_and_follow_respects_exceptions(mock_sleep, mock_proxy, exception
     with pytest.raises(MesaCIException):
         proxy = mock_proxy(side_effect=exception)
         job = LAVAJob(proxy, "")
-        log_follower = bootstrap_log_follower()
+        log_follower = bootstrap_log_follower(main_test_case="")
         follow_job_execution(job, log_follower)
 
 
@@ -242,7 +242,7 @@ def test_retriable_follow_job(
 ):
     with expectation:
         proxy = mock_proxy(side_effect=test_log, **proxy_args)
-        job: LAVAJob = retriable_follow_job(proxy, "")
+        job: LAVAJob = retriable_follow_job(proxy, "", "")
         assert job_result == job.status
         assert exit_code == job.exit_code
 
@@ -268,6 +268,7 @@ def test_simulate_a_long_wait_to_start_a_job(
             frozen_time, side_effect=side_effect, wait_time=wait_time
         ),
         "",
+        "",
     )
 
     end_time = datetime.now()
@@ -322,7 +323,7 @@ def test_log_corruption(mock_sleep, data_sequence, expected_exception, mock_prox
     proxy_logs_mock = proxy_mock.scheduler.jobs.logs
     proxy_logs_mock.side_effect = data_sequence
     with expected_exception:
-        retriable_follow_job(proxy_mock, "")
+        retriable_follow_job(proxy_mock, "", "")
 
 
 LAVA_RESULT_LOG_SCENARIOS = {
@@ -439,7 +440,7 @@ def test_full_yaml_log(mock_proxy, frozen_time, lava_job_submitter):
     try:
         time_travel_to_test_time()
         start_time = datetime.now()
-        retriable_follow_job(proxy, "")
+        retriable_follow_job(proxy, "", "")
     finally:
         try:
             # If the job fails, maybe there will be no structured log