Python testing: Fix reporting on setup_class error (project-chip#35016)

* Python testing: Fix reporting on setup_class error

Also add error text to make the error easier to find.

* Restyled by isort

* Fix lint

* Change exemption to not carry chip_error reference

chip_error is a ctypes struct with a const char* pointer internally.
This cannot be pickled, so it's causing problems with the mobly
framework.

* Fix some tests using removed class member

---------

Co-authored-by: Restyled.io <[email protected]>

src/controller/python/chip/exceptions/__init__.py

@@ -39,21 +39,17 @@ class ChipStackException(Exception):
 
 
 class ChipStackError(ChipStackException):
-    def __init__(self, chip_error: PyChipError, msg=None):
-        self._chip_error = chip_error
-        self.msg = msg if msg else "Chip Stack Error %d" % chip_error.code
+    def __init__(self, code: int, msg=None):
+        self.code = code
+        self.msg = msg if msg else "Chip Stack Error %d" % self.code
 
     @classmethod
     def from_chip_error(cls, chip_error: PyChipError) -> ChipStackError:
-        return cls(chip_error, str(chip_error))
-
-    @property
-    def chip_error(self) -> PyChipError | None:
-        return self._chip_error
+        return cls(chip_error.code, str(chip_error))
 
     @property
     def err(self) -> int:
-        return self._chip_error.code
+        return self.code
 
     def __str__(self):
         return self.msg

src/controller/python/chip/native/__init__.py

@@ -69,7 +69,7 @@ class ErrorSDKPart(enum.IntEnum):
 class PyChipError(ctypes.Structure):
     ''' The ChipError for Python library.
 
-    We are using the following struct for passing the infomations of CHIP_ERROR between C++ and Python:
+    We are using the following struct for passing the information of CHIP_ERROR between C++ and Python:
 
     ```c
     struct PyChipError
@@ -88,6 +88,10 @@ def raise_on_error(self) -> None:
             if exception is not None:  # Ensure exception is not None to avoid mypy error and only raise valid exceptions
                 raise exception
 
+    @classmethod
+    def from_code(cls, code):
+        return cls(code=code, line=0, file=ctypes.c_void_p())
+
     @property
     def is_success(self) -> bool:
         return self.code == 0

src/python_testing/TC_CADMIN_1_9.py

@@ -31,6 +31,7 @@
 from chip import ChipDeviceCtrl
 from chip.ChipDeviceCtrl import CommissioningParameters
 from chip.exceptions import ChipStackError
+from chip.native import PyChipError
 from matter_testing_support import MatterBaseTest, TestStep, async_test_body, default_matter_test_main
 from mobly import asserts
 
@@ -74,7 +75,7 @@ async def CommissionOnNetwork(
             await self.th2.CommissionOnNetwork(
                 nodeId=self.dut_node_id, setupPinCode=setup_code,
                 filterType=ChipDeviceCtrl.DiscoveryFilterType.LONG_DISCRIMINATOR, filter=self.discriminator)
-        errcode = ctx.exception.chip_error
+        errcode = PyChipError.from_code(ctx.exception.err)
         return errcode
 
     async def CommissionAttempt(

src/python_testing/TC_CGEN_2_4.py

@@ -38,6 +38,7 @@
 from chip import ChipDeviceCtrl
 from chip.ChipDeviceCtrl import CommissioningParameters
 from chip.exceptions import ChipStackError
+from chip.native import PyChipError
 from matter_testing_support import MatterBaseTest, async_test_body, default_matter_test_main
 from mobly import asserts
 
@@ -78,7 +79,7 @@ async def CommissionToStageSendCompleteAndCleanup(
             await self.th2.CommissionOnNetwork(
                 nodeId=self.dut_node_id, setupPinCode=params.setupPinCode,
                 filterType=ChipDeviceCtrl.DiscoveryFilterType.LONG_DISCRIMINATOR, filter=self.discriminator)
-        errcode = ctx.exception.chip_error
+        errcode = PyChipError.from_code(ctx.exception.err)
         asserts.assert_true(errcode.sdk_part == expectedErrorPart, 'Unexpected error type returned from CommissioningComplete')
         asserts.assert_true(errcode.sdk_code == expectedErrCode, 'Unexpected error code returned from CommissioningComplete')
         revokeCmd = Clusters.AdministratorCommissioning.Commands.RevokeCommissioning()

src/python_testing/matter_testing_support.py

@@ -27,6 +27,7 @@
 import random
 import re
 import sys
+import textwrap
 import time
 import typing
 import uuid
@@ -1123,12 +1124,60 @@ def on_fail(self, record):
         self.failed = True
         if self.runner_hook and not self.is_commissioning:
             exception = record.termination_signal.exception
-            step_duration = (datetime.now(timezone.utc) - self.step_start_time) / timedelta(microseconds=1)
-            test_duration = (datetime.now(timezone.utc) - self.test_start_time) / timedelta(microseconds=1)
+
+            try:
+                step_duration = (datetime.now(timezone.utc) - self.step_start_time) / timedelta(microseconds=1)
+            except AttributeError:
+                # If we failed during setup, these may not be populated
+                step_duration = 0
+            try:
+                test_duration = (datetime.now(timezone.utc) - self.test_start_time) / timedelta(microseconds=1)
+            except AttributeError:
+                test_duration = 0
             # TODO: I have no idea what logger, logs, request or received are. Hope None works because I have nothing to give
             self.runner_hook.step_failure(logger=None, logs=None, duration=step_duration, request=None, received=None)
             self.runner_hook.test_stop(exception=exception, duration=test_duration)
 
+            def extract_error_text() -> tuple[str, str]:
+                no_stack_trace = ("Stack Trace Unavailable", "")
+                if not record.termination_signal.stacktrace:
+                    return no_stack_trace
+                trace = record.termination_signal.stacktrace.splitlines()
+                if not trace:
+                    return no_stack_trace
+
+                if isinstance(exception, signals.TestError):
+                    # Exception gets raised by the mobly framework, so the proximal error is one line back in the stack trace
+                    assert_candidates = [idx for idx, line in enumerate(trace) if "asserts" in line and "asserts.py" not in line]
+                    if not assert_candidates:
+                        return "Unknown error, please see stack trace above", ""
+                    assert_candidate_idx = assert_candidates[-1]
+                else:
+                    # Normal assert is on the Last line
+                    assert_candidate_idx = -1
+                probable_error = trace[assert_candidate_idx]
+
+                # Find the file marker immediately above the probable error
+                file_candidates = [idx for idx, line in enumerate(trace[:assert_candidate_idx]) if "File" in line]
+                if not file_candidates:
+                    return probable_error, "Unknown file"
+                return probable_error.strip(), trace[file_candidates[-1]].strip()
+
+            probable_error, probable_file = extract_error_text()
+            logging.error(textwrap.dedent(f"""
+
+                                          ******************************************************************
+                                          *
+                                          * Test {self.current_test_info.name} failed for the following reason:
+                                          * {exception}
+                                          *
+                                          * {probable_file}
+                                          * {probable_error}
+                                          *
+                                          *******************************************************************
+
+                                          """))
+
     def on_pass(self, record):
         ''' Called by Mobly on test pass