diff mbox series

[scarthgap] arm/oeqa: Enable pexpect profiling for testcase debugging

Message ID 20240627130304.2407957-1-peter.hoyes@arm.com
State New
Headers show
Series [scarthgap] arm/oeqa: Enable pexpect profiling for testcase debugging | expand

Commit Message

Peter Hoyes June 27, 2024, 1:03 p.m. UTC 
From: Ziad Elhanafy <ziad.elhanafy@arm.com>

This patch enables logging with timestamps for individual pexpect
assertions to ease the debugging of failed tests and the tuning of
timeouts. It measures the execution time of all pexpect calls and logs
the actual duration for each.

Only "callable" pexpect calls are timed (e.g. expect, sendline, but not
before or after).

Signed-off-by: Divin Raj <divin.raj@arm.com>
Signed-off-by: Ziad Elhanafy <ziad.elhanafy@arm.com>
Signed-off-by: Peter Hoyes <peter.hoyes@arm.com>
---
 meta-arm/lib/oeqa/controllers/fvp.py | 15 +++++++++++++--
 1 file changed, 13 insertions(+), 2 deletions(-)
diff mbox series

Patch

diff --git a/meta-arm/lib/oeqa/controllers/fvp.py b/meta-arm/lib/oeqa/controllers/fvp.py
index 80f72aab..dddc10ee 100644
--- a/meta-arm/lib/oeqa/controllers/fvp.py
+++ b/meta-arm/lib/oeqa/controllers/fvp.py
@@ -3,6 +3,7 @@  import enum
 import pathlib
 import pexpect
 import os
+import time
 
 from oeqa.core.target.ssh import OESSHTarget
 from fvp import runner
@@ -127,9 +128,19 @@  class OEFVPTarget(OESSHTarget):
         def call_pexpect(terminal, *args, **kwargs):
             attr = getattr(self.terminals[terminal], name)
             if callable(attr):
-                return attr(*args, **kwargs)
+                self.logger.debug(f"Calling {name} on {terminal} : with arguments -> {args}  :  {kwargs}")
+                start_time = time.monotonic()  # Record the start time
+
+                attr = getattr(self.terminals[terminal], name)
+                result = attr(*args, **kwargs)
+
+                end_time = time.monotonic()  # Record the end time
+                elapsed_time = end_time - start_time
+                self.logger.debug(f"Execution time for result: [ {result} ] - elapsed_time: {elapsed_time} seconds")
             else:
-                return attr
+                result = attr
+
+            return result
 
         return call_pexpect