From 2fba14b340c4b75017ac0e04d75caead3233c39a Mon Sep 17 00:00:00 2001
From: Matt Borgerson <contact@mborgerson.com>
Date: Tue, 13 Jan 2026 21:44:10 -0700
Subject: [PATCH] Include subtest duration in report

---
 xemutest/__main__.py                     |  3 ++-
 xemutest/test_base.py                    |  7 +++++--
 xemutest/tests/test_nxdk_pgraph_tests.py | 18 ++++++++++++------
 3 files changed, 19 insertions(+), 9 deletions(-)

diff --git a/xemutest/__main__.py b/xemutest/__main__.py
index 4ba7a59..69307de 100644
--- a/xemutest/__main__.py
+++ b/xemutest/__main__.py
@@ -137,6 +137,7 @@ def main():
                 [
                     full_name,
                     format_status(test_result),
+                    test_result.duration,
                     test_result.message,
                 ]
             ]
@@ -149,7 +150,7 @@ def main():
         for test_result in test_results_summary.values():
             rows.extend(collect_rows(test_result))
 
-        summary.add_table(headers=["Test", "Status", "Details"], rows=rows)
+        summary.add_table(headers=["Test", "Status", "Duration", "Details"], rows=rows)
         summary.write()
 
     exit(0 if result else 1)
diff --git a/xemutest/test_base.py b/xemutest/test_base.py
index d80ed27..6aceb68 100755
--- a/xemutest/test_base.py
+++ b/xemutest/test_base.py
@@ -29,6 +29,7 @@ class TestResult:
     name: str
     status: TestStatus
     message: str = ""
+    duration: str = ""  # Duration string (e.g., "43ms")
     subtests: list["TestResult"] = field(default_factory=list)
 
     @property
@@ -72,11 +73,13 @@ class TestBase:
         """
         pass
 
-    def add_subtest_result(self, name: str, status: TestStatus, message: str = ""):
+    def add_subtest_result(
+        self, name: str, status: TestStatus, message: str = "", duration: str = ""
+    ):
         """Add a subtest result to the test results."""
         if self._test_result is None:
             return
-        self._test_result.subtests.append(TestResult(name, status, message))
+        self._test_result.subtests.append(TestResult(name, status, message, duration))
         if status == TestStatus.FAILED:
             self._test_result.status = TestStatus.FAILED
 
diff --git a/xemutest/tests/test_nxdk_pgraph_tests.py b/xemutest/tests/test_nxdk_pgraph_tests.py
index bc817b5..af7f46b 100644
--- a/xemutest/tests/test_nxdk_pgraph_tests.py
+++ b/xemutest/tests/test_nxdk_pgraph_tests.py
@@ -42,11 +42,14 @@ class PgraphTestResult:
     renderer: str
     status: PgraphTestStatus
     message: str = ""
+    duration: str = ""  # Duration string from progress log (e.g., "43ms")
 
 
 @dataclass
 class PgraphTestSuiteAnalysis:
-    tests_completed: list[PgraphTestId] = field(default_factory=list)
+    tests_completed: list[tuple[PgraphTestId, str]] = field(
+        default_factory=list
+    )  # (test_id, duration)
     tests_incomplete: list[PgraphTestId] = field(default_factory=list)
 
 
@@ -142,11 +145,12 @@ renderer = '{renderer.upper()}'
                     )
 
                     # Track completed tests (pending comparison)
-                    for test_id in progress_analysis.tests_completed:
+                    for test_id, duration in progress_analysis.tests_completed:
                         self._pgraph_results[(renderer, test_id)] = PgraphTestResult(
                             test_id=test_id,
                             renderer=renderer,
                             status=PgraphTestStatus.COMPLETED,
+                            duration=duration,
                         )
 
                     # Track incomplete tests
@@ -158,7 +162,9 @@ renderer = '{renderer.upper()}'
                             message="Test did not complete",
                         )
 
-                    tests_ran.extend(progress_analysis.tests_completed)
+                    tests_ran.extend(
+                        test_id for test_id, _ in progress_analysis.tests_completed
+                    )
                     tests_ran.extend(progress_analysis.tests_incomplete)
 
                     log.info(
@@ -232,11 +238,11 @@ renderer = '{renderer.upper()}'
                     suite, test = starting_matches.group("suite", "test")
                     test_started = PgraphTestId(suite, test)
                 elif completed_matches := COMPLETED_RE.match(line):
-                    test = completed_matches.group("test")
+                    test, duration = completed_matches.group("test", "duration")
                     assert (
                         test_started is not None and test_started.name == test
                     ), "Unmatched starting/completed sequence"
-                    analysis.tests_completed.append(test_started)
+                    analysis.tests_completed.append((test_started, duration))
                     test_started = None
                 elif line == "Testing completed normally, closing log.":
                     continue
@@ -307,7 +313,7 @@ renderer = '{renderer.upper()}'
                 if status == TestStatus.FAILED:
                     has_failures = True
                     log.error("%s: %s", test_name, result.status.name)
-                self.add_subtest_result(test_name, status, message)
+                self.add_subtest_result(test_name, status, message, result.duration)
 
             if has_failures:
                 failed_count = sum(