From 5f647901524c945058a7495a9ff999d191718334 Mon Sep 17 00:00:00 2001 From: Ziad Elhanafy Date: Thu, 27 Jun 2024 13:57:00 +0100 Subject: [PATCH] arm/oeqa: Enable pexpect profiling for testcase debugging 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 Signed-off-by: Ziad Elhanafy Signed-off-by: Peter Hoyes Signed-off-by: Jon Mason --- meta-arm/lib/oeqa/controllers/fvp.py | 15 +++++++++++++-- 1 file changed, 13 insertions(+), 2 deletions(-) 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