From patchwork Thu Jun 27 13:03:04 2024 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Peter Hoyes X-Patchwork-Id: 45696 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from aws-us-west-2-korg-lkml-1.web.codeaurora.org (localhost.localdomain [127.0.0.1]) by smtp.lore.kernel.org (Postfix) with ESMTP id 35A7CC2BD09 for ; Thu, 27 Jun 2024 13:03:23 +0000 (UTC) Received: from foss.arm.com (foss.arm.com [217.140.110.172]) by mx.groups.io with SMTP id smtpd.web10.7309.1719493399951807689 for ; Thu, 27 Jun 2024 06:03:20 -0700 Authentication-Results: mx.groups.io; dkim=none (message not signed); spf=pass (domain: arm.com, ip: 217.140.110.172, mailfrom: peter.hoyes@arm.com) Received: from usa-sjc-imap-foss1.foss.arm.com (unknown [10.121.207.14]) by usa-sjc-mx-foss1.foss.arm.com (Postfix) with ESMTP id 46C78367; Thu, 27 Jun 2024 06:03:44 -0700 (PDT) Received: from e133390.cambridge.arm.com (e133390.arm.com [10.1.36.164]) by usa-sjc-imap-foss1.foss.arm.com (Postfix) with ESMTPSA id 433F33F766; Thu, 27 Jun 2024 06:03:18 -0700 (PDT) From: Peter Hoyes To: meta-arm@lists.yoctoproject.org Cc: Ziad Elhanafy , Divin Raj Subject: [PATCH scarthgap] arm/oeqa: Enable pexpect profiling for testcase debugging Date: Thu, 27 Jun 2024 14:03:04 +0100 Message-Id: <20240627130304.2407957-1-peter.hoyes@arm.com> X-Mailer: git-send-email 2.34.1 MIME-Version: 1.0 List-Id: X-Webhook-Received: from li982-79.members.linode.com [45.33.32.79] by aws-us-west-2-korg-lkml-1.web.codeaurora.org with HTTPS for ; Thu, 27 Jun 2024 13:03:23 -0000 X-Groupsio-URL: https://lists.yoctoproject.org/g/meta-arm/message/5847 From: Ziad Elhanafy 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 --- 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