diff mbox series

[4/5] arm/oeqa: Log the FVP output in OEFVPSSHTarget

Message ID 20221115150116.314729-4-peter.hoyes@arm.com
State New
Headers show
Series [1/5] arm/fvp: Join cli arguments in verbose logging | expand

Commit Message

Peter Hoyes Nov. 15, 2022, 3:01 p.m. UTC
From: Peter Hoyes <Peter.Hoyes@arm.com>

It is often useful to inspect the FVP output after running the tests.

Refactor OEFVPSerialTarget._create_logfile into
OEFVPSSHTarget._create_log_filename, so that all FVP test controllers
are able to create secondary log files.

Pass a filehandle to the stdout argument of run_fvp so that the FVP
output is asynchronously logged to a file. Change the port parsing logic
to read back from the same log file instead of reading the stdout
directly.

Issue-Id: SCM-5314
Signed-off-by: Peter Hoyes <Peter.Hoyes@arm.com>
Change-Id: I2ddb423fa0d896c13d3e96884858c680c4d34555
---
 documentation/oeqa-fvp.md            |  2 +-
 meta-arm/lib/fvp/runner.py           |  4 +-
 meta-arm/lib/oeqa/controllers/fvp.py | 97 +++++++++++++++-------------
 3 files changed, 54 insertions(+), 49 deletions(-)
diff mbox series

Patch

diff --git a/documentation/oeqa-fvp.md b/documentation/oeqa-fvp.md
index 582dd38b..e1468851 100644
--- a/documentation/oeqa-fvp.md
+++ b/documentation/oeqa-fvp.md
@@ -4,7 +4,7 @@  OE-Core's [oeqa][OEQA] framework provides a method of performing runtime tests o
 
 Tests can be configured to run automatically post-build by setting the variable `TESTIMAGE_AUTO="1"`, e.g. in your Kas file or local.conf.
 
-There are two main methods of testing, using different test "targets".
+There are two main methods of testing, using different test "targets". Both test targets generate an additional log file with the prefix 'fvp_log' in the image recipe's `${WORKDIR}/testimage` containing the FVP's stdout.
 
 ## OEFVPTarget
 
diff --git a/meta-arm/lib/fvp/runner.py b/meta-arm/lib/fvp/runner.py
index 5c5ded28..f55c579d 100644
--- a/meta-arm/lib/fvp/runner.py
+++ b/meta-arm/lib/fvp/runner.py
@@ -77,7 +77,7 @@  class FVPRunner:
         self._telnets = []
         self._pexpects = []
 
-    def start(self, config, extra_args=[], terminal_choice="none"):
+    def start(self, config, extra_args=[], terminal_choice="none", stdout=subprocess.PIPE):
         cli = cli_from_config(config, terminal_choice)
         cli += extra_args
 
@@ -91,7 +91,7 @@  class FVPRunner:
         self._logger.debug(f"Constructed FVP call: {shlex.join(cli)}")
         self._fvp_process = subprocess.Popen(
             cli,
-            stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, stderr=subprocess.STDOUT,
+            stdin=subprocess.DEVNULL, stdout=stdout, stderr=subprocess.STDOUT,
             env=env)
 
     def stop(self):
diff --git a/meta-arm/lib/oeqa/controllers/fvp.py b/meta-arm/lib/oeqa/controllers/fvp.py
index 0c3c2214..e8a094f1 100644
--- a/meta-arm/lib/oeqa/controllers/fvp.py
+++ b/meta-arm/lib/oeqa/controllers/fvp.py
@@ -12,7 +12,7 @@  class OEFVPSSHTarget(OESSHTarget):
     Contains common logic to start and stop an FVP.
     """
     def __init__(self, logger, target_ip, server_ip, timeout=300, user='root',
-                 port=None, dir_image=None, rootfs=None, **kwargs):
+                 port=None, dir_image=None, rootfs=None, bootlog=None, **kwargs):
         super().__init__(logger, target_ip, server_ip, timeout, user, port)
         image_dir = pathlib.Path(dir_image)
         # rootfs may have multiple extensions so we need to strip *all* suffixes
@@ -20,6 +20,7 @@  class OEFVPSSHTarget(OESSHTarget):
         basename = basename.name.replace("".join(basename.suffixes), "")
         self.fvpconf = image_dir / (basename + ".fvpconf")
         self.config = conffile.load(self.fvpconf)
+        self.bootlog = bootlog
 
         if not self.fvpconf.exists():
             raise FileNotFoundError(f"Cannot find {self.fvpconf}")
@@ -28,8 +29,9 @@  class OEFVPSSHTarget(OESSHTarget):
         pass
 
     def start(self, **kwargs):
+        self.fvp_log = self._create_logfile("fvp")
         self.fvp = runner.FVPRunner(self.logger)
-        self.fvp.start(self.config)
+        self.fvp.start(self.config, stdout=self.fvp_log)
         self.logger.debug(f"Started FVP PID {self.fvp.pid()}")
         self._after_start()
 
@@ -37,6 +39,22 @@  class OEFVPSSHTarget(OESSHTarget):
         returncode = self.fvp.stop()
         self.logger.debug(f"Stopped FVP with return code {returncode}")
 
+    def _create_logfile(self, name):
+        if not self.bootlog:
+            return None
+
+        test_log_path = pathlib.Path(self.bootlog).parent
+        test_log_suffix = pathlib.Path(self.bootlog).suffix
+        fvp_log_file = f"{name}_log{test_log_suffix}"
+        fvp_log_path = pathlib.Path(test_log_path, fvp_log_file)
+        fvp_log_symlink = pathlib.Path(test_log_path, f"{name}_log")
+        try:
+            os.remove(fvp_log_symlink)
+        except:
+            pass
+        os.symlink(fvp_log_file, fvp_log_symlink)
+        return open(fvp_log_path, 'wb')
+
 
 class OEFVPTarget(OEFVPSSHTarget):
     """
@@ -44,33 +62,34 @@  class OEFVPTarget(OEFVPSSHTarget):
     waits for a Linux shell before returning to ensure that SSH commands work
     with the default test dependencies.
     """
-    def __init__(self, logger, target_ip, server_ip, bootlog=None, **kwargs):
+    def __init__(self, logger, target_ip, server_ip, **kwargs):
         super().__init__(logger, target_ip, server_ip, **kwargs)
-        self.logfile = bootlog and open(bootlog, "wb") or None
+        self.logfile = self.bootlog and open(self.bootlog, "wb") or None
 
         # FVPs boot slowly, so allow ten minutes
         self.boot_timeout = 10 * 60
 
     def _after_start(self):
-        parser = runner.ConsolePortParser(self.fvp.stdout)
-        self.logger.debug(f"Awaiting console on terminal {self.config['consoles']['default']}")
-        port = parser.parse_port(self.config['consoles']['default'])
-        console = self.fvp.create_pexpect(port)
-        try:
-            console.expect("login\\:", timeout=self.boot_timeout)
-            self.logger.debug("Found login prompt")
-        except pexpect.TIMEOUT:
-            self.logger.info("Timed out waiting for login prompt.")
-            self.logger.info("Boot log follows:")
-            self.logger.info(b"\n".join(console.before.splitlines()[-200:]).decode("utf-8", errors="replace"))
-            raise RuntimeError("Failed to start FVP.")
+        with open(self.fvp_log.name, 'rb') as logfile:
+            parser = runner.ConsolePortParser(logfile)
+            self.logger.debug(f"Awaiting console on terminal {self.config['consoles']['default']}")
+            port = parser.parse_port(self.config['consoles']['default'])
+            console = self.fvp.create_pexpect(port)
+            try:
+                console.expect("login\\:", timeout=self.boot_timeout)
+                self.logger.debug("Found login prompt")
+            except pexpect.TIMEOUT:
+                self.logger.info("Timed out waiting for login prompt.")
+                self.logger.info("Boot log follows:")
+                self.logger.info(b"\n".join(console.before.splitlines()[-200:]).decode("utf-8", errors="replace"))
+                raise RuntimeError("Failed to start FVP.")
 
 
 class OEFVPSerialTarget(OEFVPSSHTarget):
     """
     This target is intended for interaction with the target over one or more
     telnet consoles using pexpect.
-    
+
     This still depends on OEFVPSSHTarget so SSH commands can still be run on
     the target, but note that this class does not inherently guarantee that
     the SSH server is running prior to running test cases. Test cases that use
@@ -79,39 +98,25 @@  class OEFVPSerialTarget(OEFVPSSHTarget):
     """
     DEFAULT_CONSOLE = "default"
 
-    def __init__(self, logger, target_ip, server_ip, bootlog=None, **kwargs):
+    def __init__(self, logger, target_ip, server_ip, **kwargs):
         super().__init__(logger, target_ip, server_ip, **kwargs)
         self.terminals = {}
 
-        self.test_log_path = pathlib.Path(bootlog).parent
-        self.test_log_suffix = pathlib.Path(bootlog).suffix
-        self.bootlog = bootlog
-
-    def _create_logfile(self, name):
-        fvp_log_file = f"{name}_log{self.test_log_suffix}"
-        fvp_log_path = pathlib.Path(self.test_log_path, fvp_log_file)
-        fvp_log_symlink = pathlib.Path(self.test_log_path, f"{name}_log")
-        try:
-            os.remove(fvp_log_symlink)
-        except:
-            pass
-        os.symlink(fvp_log_file, fvp_log_symlink)
-        return open(fvp_log_path, 'wb')
-
     def _after_start(self):
-        parser = runner.ConsolePortParser(self.fvp.stdout)
-        for name, console in self.config["consoles"].items():
-            logfile = self._create_logfile(name)
-            self.logger.info(f'Creating terminal {name} on {console}')
-            port = parser.parse_port(console)
-            self.terminals[name] = \
-                self.fvp.create_pexpect(port, logfile=logfile)
-
-            # testimage.bbclass expects to see a log file at `bootlog`,
-            # so make a symlink to the 'default' log file
-            if name == 'default':
-                default_test_file = f"{name}_log{self.test_log_suffix}"
-                os.symlink(default_test_file, self.bootlog)
+        with open(self.fvp_log.name, 'rb') as logfile:
+            parser = runner.ConsolePortParser(logfile)
+            for name, console in self.config["consoles"].items():
+                logfile = self._create_logfile(name)
+                self.logger.info(f'Creating terminal {name} on {console}')
+                port = parser.parse_port(console)
+                self.terminals[name] = \
+                    self.fvp.create_pexpect(port, logfile=logfile)
+
+                # testimage.bbclass expects to see a log file at `bootlog`,
+                # so make a symlink to the 'default' log file
+                if name == 'default':
+                    default_test_file = f"{name}_log{self.test_log_suffix}"
+                    os.symlink(default_test_file, self.bootlog)
 
     def _get_terminal(self, name):
         return self.terminals[name]