Make Phase name (or any other executable unit name) known in finalize_from_phase_outcome so that we can mention it on the finalization message.

I also updated all the other error messages in finalize_from_test_outcome to use the phase name.

PiperOrigin-RevId: 508689999

Author: OpenHTF Owners

openhtf/core/test_executor.py

@@ -108,6 +108,7 @@ def __init__(self, test_descriptor: 'test_descriptor.TestDescriptor',
     self._phase_exec = None  # type: Optional[phase_executor.PhaseExecutor]
     self.uid = execution_uid
     self._last_outcome = None  # type: Optional[phase_executor.PhaseExecutionOutcome]
+    self._last_execution_unit: str = None
     self._abort = threading.Event()
     self._full_abort = threading.Event()
     # This is a reentrant lock so that the teardown logic that prevents aborts
@@ -235,6 +236,7 @@ def _initialize_plugs(
       # Record the equivalent failure outcome and exit early.
       self._last_outcome = phase_executor.PhaseExecutionOutcome(
           phase_executor.ExceptionInfo(*sys.exc_info()))
+      self._last_execution_unit = 'Plugs Initialization'
       return True
 
   def _execute_test_start(self) -> bool:
@@ -264,6 +266,7 @@ def _execute_test_start(self) -> bool:
 
     if outcome.is_terminal:
       self._last_outcome = outcome
+      self._last_execution_unit = 'TestStart'
       return True
 
     if self.test_state.test_record.dut_id is None:
@@ -296,7 +299,9 @@ def _execute_test_teardown(self) -> None:
       self.logger.debug('Finishing test with outcome ABORTED.')
       self.test_state.abort()
     elif self._last_outcome and self._last_outcome.is_terminal:
-      self.test_state.finalize_from_phase_outcome(self._last_outcome)
+      self.test_state.finalize_from_phase_outcome(
+          self._last_outcome, self._last_execution_unit
+      )
     else:
       self.test_state.finalize_normally()
 
@@ -333,6 +338,7 @@ def _execute_phase(self, phase: phase_descriptor.PhaseDescriptor,
     if outcome.is_terminal:
       if not self._last_outcome:
         self._last_outcome = outcome
+        self._last_execution_unit = phase.name
       return _ExecutorReturn.TERMINAL
 
     if outcome.is_fail_subtest:
@@ -354,6 +360,7 @@ def _execute_checkpoint(self, checkpoint: phase_branches.Checkpoint,
     if outcome.is_terminal:
       if not self._last_outcome:
         self._last_outcome = outcome
+        self._last_execution_unit = checkpoint.name
       return _ExecutorReturn.TERMINAL
 
     if outcome.is_fail_subtest:
@@ -600,6 +607,7 @@ def _execute_test_diagnoser(
         # Record the equivalent failure outcome and exit early.
         self._last_outcome = phase_executor.PhaseExecutionOutcome(
             phase_executor.ExceptionInfo(*sys.exc_info()))
+        self._last_execution_unit = diagnoser.name
 
   def _execute_test_diagnosers(self) -> None:
     for diagnoser in self._test_options.diagnosers:

openhtf/core/test_state.py

@@ -382,7 +382,9 @@ def set_status_running(self) -> None:
 
   def finalize_from_phase_outcome(
       self,
-      phase_execution_outcome: phase_executor.PhaseExecutionOutcome) -> None:
+      phase_execution_outcome: phase_executor.PhaseExecutionOutcome,
+      phase_name: str,
+  ) -> None:
     """Finalize due to the given phase outcome."""
     if self._is_aborted():
       return
@@ -400,39 +402,49 @@ def finalize_from_phase_outcome(
       self.test_record.add_outcome_details(code, description)
       if self._outcome_is_failure_exception(phase_execution_outcome):
         self.state_logger.error(
-            'Outcome will be FAIL since exception was of type %s',
-            phase_execution_outcome.phase_result.exc_val)
+            f'Outcome of {phase_name} will be FAIL since exception was of type'
+            ' {phase_execution_outcome.phase_result.exc_val}'
+        )
         self._finalize(test_record.Outcome.FAIL)
       else:
         self.state_logger.critical(
-            'Finishing test execution early due to an exception raised during '
-            'phase execution; outcome ERROR.')
+            f'Finishing test execution of {phase_name} early due to an '
+            'exception raised during phase execution; outcome ERROR.'
+        )
         # Enable CLI printing of the full traceback with the -v flag.
         if isinstance(result, phase_executor.ExceptionInfo):
           self.state_logger.critical(
-              'Traceback:%s%s%s%s',
+              'Traceback:%s%s%s%s\n in executing %s',
               os.linesep,
               phase_execution_outcome.phase_result.get_traceback_string(),
               os.linesep,
               description,
+              phase_name,
           )
         else:
           self.state_logger.critical(
-              'Description:%s',
-              description,
+              f'Description:{description}, PhaseName:{phase_name}'
           )
         self._finalize(test_record.Outcome.ERROR)
     elif phase_execution_outcome.is_timeout:
-      self.state_logger.error('Finishing test execution early due to '
-                              'phase timeout, outcome TIMEOUT.')
-      self.test_record.add_outcome_details('TIMEOUT',
-                                           'A phase hit its timeout.')
+      self.state_logger.error(
+          'Finishing test execution early due to '
+          f'phase {phase_name} experiencing timeout, '
+          'outcome TIMEOUT.'
+      )
+      self.test_record.add_outcome_details(
+          'TIMEOUT', f'Phase {phase_name} hit its timeout.'
+      )
       self._finalize(test_record.Outcome.TIMEOUT)
     elif phase_execution_outcome.phase_result == openhtf.PhaseResult.STOP:
-      self.state_logger.error('Finishing test execution early due to '
-                              'PhaseResult.STOP, outcome FAIL.')
-      self.test_record.add_outcome_details('STOP',
-                                           'A phase stopped the test run.')
+      self.state_logger.error(
+          'Finishing test execution early due to '
+          f'{phase_name} causing PhaseResult.STOP, '
+          'outcome FAIL.'
+      )
+      self.test_record.add_outcome_details(
+          'STOP', f'Phase {phase_name} stopped the test run.'
+      )
       self._finalize(test_record.Outcome.FAIL)
 
   def finalize_normally(self) -> None:

test/test_state_test.py

@@ -243,7 +243,7 @@ def test_test_state_cache(self):
   def test_test_state_finalize_from_phase_outcome(
       self, phase_exe_outcome: phase_executor.PhaseExecutionOutcome,
       test_record_outcome: test_record.Outcome):
-    self.test_state.finalize_from_phase_outcome(phase_exe_outcome)
+    self.test_state.finalize_from_phase_outcome(phase_exe_outcome, 'MyPhase')
     self.assertEqual(self.test_state.test_record.outcome, test_record_outcome)
 
   def test_test_state_finalize_from_phase_outcome_exception_info(self):
@@ -252,6 +252,6 @@ def test_test_state_finalize_from_phase_outcome_exception_info(self):
     except ValueError:
       phase_exe_outcome = phase_executor.PhaseExecutionOutcome(
           phase_executor.ExceptionInfo(*sys.exc_info()))
-      self.test_state.finalize_from_phase_outcome(phase_exe_outcome)
+      self.test_state.finalize_from_phase_outcome(phase_exe_outcome, 'MyPhase')
     self.assertEqual(self.test_state.test_record.outcome,
                      test_record.Outcome.ERROR)