From dbaaef7dbfe3a932279c2d77f056a30575cc97cb Mon Sep 17 00:00:00 2001 From: "Daniel P. Berrangé" Date: Thu, 21 Nov 2024 16:57:29 +0000 Subject: tests/functional: automatically clean up scratch files after tests MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The build/tests/functional subdirectories are consuming huge amounts of disk space. Split the location for scratch files into a 'scratch' sub-directory, separate from log files, and delete it upon completion of each test. The new env variable QEMU_TEST_KEEP_SCRATCH can be set to preserve this scratch dir for debugging access if required. Reviewed-by: Alex Bennée Signed-off-by: Daniel P. Berrangé Message-Id: <20241121154218.1423005-3-berrange@redhat.com> Signed-off-by: Alex Bennée Message-Id: <20241121165806.476008-3-alex.bennee@linaro.org> --- tests/functional/qemu_test/testcase.py | 14 +++++++++----- 1 file changed, 9 insertions(+), 5 deletions(-) (limited to 'tests/functional/qemu_test/testcase.py') diff --git a/tests/functional/qemu_test/testcase.py b/tests/functional/qemu_test/testcase.py index 411978b5ef..b9418e2ac0 100644 --- a/tests/functional/qemu_test/testcase.py +++ b/tests/functional/qemu_test/testcase.py @@ -13,8 +13,9 @@ import logging import os -import subprocess import pycotap +import shutil +import subprocess import sys import unittest import uuid @@ -40,11 +41,12 @@ class QemuBaseTest(unittest.TestCase): self.assertIsNotNone(self.qemu_bin, 'QEMU_TEST_QEMU_BINARY must be set') self.arch = self.qemu_bin.split('-')[-1] - self.workdir = os.path.join(BUILD_DIR, 'tests/functional', self.arch, - self.id()) + self.outputdir = os.path.join(BUILD_DIR, 'tests', 'functional', + self.arch, self.id()) + self.workdir = os.path.join(self.outputdir, 'scratch') os.makedirs(self.workdir, exist_ok=True) - self.logdir = self.workdir + self.logdir = self.outputdir self.log_filename = os.path.join(self.logdir, 'base.log') self.log = logging.getLogger('qemu-test') self.log.setLevel(logging.DEBUG) @@ -56,6 +58,8 @@ class QemuBaseTest(unittest.TestCase): self.log.addHandler(self._log_fh) def tearDown(self): + if "QEMU_TEST_KEEP_SCRATCH" not in os.environ: + shutil.rmtree(self.workdir) self.log.removeHandler(self._log_fh) def main(): @@ -108,7 +112,7 @@ class QemuSystemTest(QemuBaseTest): console_log = logging.getLogger('console') console_log.setLevel(logging.DEBUG) - self.console_log_name = os.path.join(self.workdir, 'console.log') + self.console_log_name = os.path.join(self.logdir, 'console.log') self._console_log_fh = logging.FileHandler(self.console_log_name, mode='w') self._console_log_fh.setLevel(logging.DEBUG) -- cgit 1.4.1 From e6d69e0f3b83b7c60d024f41f5eaf130755b090c Mon Sep 17 00:00:00 2001 From: "Daniel P. Berrangé" Date: Thu, 21 Nov 2024 16:57:36 +0000 Subject: tests/functional: put QEMUMachine logs in testcase log directory MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit We are not passing the 'log_dir' parameter to QEMUMachine, so the QEMU stdout/err logs are being placed in a temp directory and thus deleted after execution. This makes them inaccessible as gitlab CI artifacts. Pass the testcase log directory path into QEMUMachine to make the logs persistent. Reviewed-by: Alex Bennée Signed-off-by: Daniel P. Berrangé Message-Id: <20241121154218.1423005-10-berrange@redhat.com> Signed-off-by: Alex Bennée Message-Id: <20241121165806.476008-10-alex.bennee@linaro.org> --- tests/functional/qemu_test/testcase.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) (limited to 'tests/functional/qemu_test/testcase.py') diff --git a/tests/functional/qemu_test/testcase.py b/tests/functional/qemu_test/testcase.py index b9418e2ac0..ca13af244b 100644 --- a/tests/functional/qemu_test/testcase.py +++ b/tests/functional/qemu_test/testcase.py @@ -163,10 +163,11 @@ class QemuSystemTest(QemuBaseTest): self.skipTest('no support for device ' + devicename) def _new_vm(self, name, *args): - vm = QEMUMachine(self.qemu_bin, base_temp_dir=self.workdir) + vm = QEMUMachine(self.qemu_bin, + base_temp_dir=self.workdir, + log_dir=self.logdir) self.log.debug('QEMUMachine "%s" created', name) self.log.debug('QEMUMachine "%s" temp_dir: %s', name, vm.temp_dir) - self.log.debug('QEMUMachine "%s" log_dir: %s', name, vm.log_dir) if args: vm.add_args(*args) return vm -- cgit 1.4.1 From 9f85aff93f5dcedb70819a5ed7796b6df90fdf2d Mon Sep 17 00:00:00 2001 From: "Daniel P. Berrangé" Date: Thu, 21 Nov 2024 16:57:37 +0000 Subject: tests/functional: honour requested test VM name in QEMUMachine MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The functional test case class is going to the trouble of passing around a machine name, but then fails to give this QEMUMachine. As a result, QEMUMachine will create a completely random name. Since log file names match the machine name, this results in log files accumulating over time. Reviewed-by: Thomas Huth Signed-off-by: Daniel P. Berrangé Message-Id: <20241121154218.1423005-11-berrange@redhat.com> Signed-off-by: Alex Bennée Message-Id: <20241121165806.476008-11-alex.bennee@linaro.org> --- tests/functional/qemu_test/testcase.py | 1 + 1 file changed, 1 insertion(+) (limited to 'tests/functional/qemu_test/testcase.py') diff --git a/tests/functional/qemu_test/testcase.py b/tests/functional/qemu_test/testcase.py index ca13af244b..f9c9de1166 100644 --- a/tests/functional/qemu_test/testcase.py +++ b/tests/functional/qemu_test/testcase.py @@ -164,6 +164,7 @@ class QemuSystemTest(QemuBaseTest): def _new_vm(self, name, *args): vm = QEMUMachine(self.qemu_bin, + name=name, base_temp_dir=self.workdir, log_dir=self.logdir) self.log.debug('QEMUMachine "%s" created', name) -- cgit 1.4.1 From 9bcfead1ee1c5d37c39b129557e1528879270fea Mon Sep 17 00:00:00 2001 From: "Daniel P. Berrangé" Date: Thu, 21 Nov 2024 16:57:38 +0000 Subject: tests/functional: enable debug logging for QEMUMachine MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Set the 'qemu.machine' logger to 'DEBUG' level, to ensure we see log messages related to the QEMUMachine class. Most importantly this ensures we capture the full QEMU command line args for instances we spawn. Signed-off-by: Daniel P. Berrangé Message-Id: <20241121154218.1423005-12-berrange@redhat.com> Tested-by: Thomas Huth Reviewed-by: Thomas Huth Signed-off-by: Alex Bennée Reviewed-by: Thomas Huth Message-Id: <20241121165806.476008-12-alex.bennee@linaro.org> --- tests/functional/qemu_test/testcase.py | 6 ++++++ 1 file changed, 6 insertions(+) (limited to 'tests/functional/qemu_test/testcase.py') diff --git a/tests/functional/qemu_test/testcase.py b/tests/functional/qemu_test/testcase.py index f9c9de1166..e2a329c3e5 100644 --- a/tests/functional/qemu_test/testcase.py +++ b/tests/functional/qemu_test/testcase.py @@ -57,9 +57,15 @@ class QemuBaseTest(unittest.TestCase): self._log_fh.setFormatter(fileFormatter) self.log.addHandler(self._log_fh) + # Capture QEMUMachine logging + self.machinelog = logging.getLogger('qemu.machine') + self.machinelog.setLevel(logging.DEBUG) + self.machinelog.addHandler(self._log_fh) + def tearDown(self): if "QEMU_TEST_KEEP_SCRATCH" not in os.environ: shutil.rmtree(self.workdir) + self.machinelog.removeHandler(self._log_fh) self.log.removeHandler(self._log_fh) def main(): -- cgit 1.4.1 From 1a8755a51eef11360af92adf71fed6a20a1260b2 Mon Sep 17 00:00:00 2001 From: "Daniel P. Berrangé" Date: Thu, 21 Nov 2024 16:57:44 +0000 Subject: tests/functional: add a QMP backdoor for debugging stalled tests MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Support the QEMU_TEST_QMP_BACKDOOR=backdoor.sock env variable as a way to get a QMP backdoor for debugging a stalled QEMU test. Most typically this would be used if running the tests directly: $ QEMU_TEST_QMP_BACKDOOR=backdoor.sock \ QEMU_TEST_QEMU_BINARY=./build/qemu-system-arm \ PYTHONPATH=./python \ ./tests/functional/test_arm_tuxrun.py And then, when the test stalls, in a second shell run: $ ./scripts/qmp/qmp-shell backdoor.sock Signed-off-by: Daniel P. Berrangé Message-Id: <20241121154218.1423005-18-berrange@redhat.com> Reviewed-by: Thomas Huth Signed-off-by: Alex Bennée Message-Id: <20241121165806.476008-18-alex.bennee@linaro.org> --- docs/devel/testing/functional.rst | 10 ++++++++++ tests/functional/qemu_test/testcase.py | 7 +++++++ 2 files changed, 17 insertions(+) (limited to 'tests/functional/qemu_test/testcase.py') diff --git a/docs/devel/testing/functional.rst b/docs/devel/testing/functional.rst index 6b5d0c5b98..b8ad7b0bf7 100644 --- a/docs/devel/testing/functional.rst +++ b/docs/devel/testing/functional.rst @@ -176,6 +176,16 @@ primarily depend on the value of the ``qemu_bin`` class attribute. If it is not explicitly set by the test code, its default value will be the result the QEMU_TEST_QEMU_BINARY environment variable. +Debugging hung QEMU +^^^^^^^^^^^^^^^^^^^ + +When test cases go wrong it may be helpful to debug a stalled QEMU +process. While the QEMUMachine class owns the primary QMP monitor +socket, it is possible to request a second QMP monitor be created +by setting the ``QEMU_TEST_QMP_BACKDOOR`` env variable to refer +to a UNIX socket name. The ``qmp-shell`` command can then be +attached to the stalled QEMU to examine its live state. + Attribute reference ------------------- diff --git a/tests/functional/qemu_test/testcase.py b/tests/functional/qemu_test/testcase.py index e2a329c3e5..fceafb32b0 100644 --- a/tests/functional/qemu_test/testcase.py +++ b/tests/functional/qemu_test/testcase.py @@ -175,6 +175,13 @@ class QemuSystemTest(QemuBaseTest): log_dir=self.logdir) self.log.debug('QEMUMachine "%s" created', name) self.log.debug('QEMUMachine "%s" temp_dir: %s', name, vm.temp_dir) + + sockpath = os.environ.get("QEMU_TEST_QMP_BACKDOOR", None) + if sockpath is not None: + vm.add_args("-chardev", + f"socket,id=backdoor,path={sockpath},server=on,wait=off", + "-mon", "chardev=backdoor,mode=control") + if args: vm.add_args(*args) return vm -- cgit 1.4.1 From f5578e427f95cb34436a18c0cd4417d4280e61bc Mon Sep 17 00:00:00 2001 From: "Daniel P. Berrangé" Date: Thu, 21 Nov 2024 16:57:45 +0000 Subject: tests/functional: avoid accessing log_filename on earlier failures MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit If a failure occurs early in the QemuBaseTest constructor, the 'log_filename' object atttribute may not exist yet. This happens most notably if the QEMU_TEST_QEMU_BINARY is not set. We can't initialize 'log_filename' earlier as we use the binary to identify the architecture which is then used to build the path in which the logs are stored. Signed-off-by: Daniel P. Berrangé Message-Id: <20241121154218.1423005-19-berrange@redhat.com> Reviewed-by: Thomas Huth Signed-off-by: Alex Bennée Message-Id: <20241121165806.476008-19-alex.bennee@linaro.org> --- tests/functional/qemu_test/testcase.py | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) (limited to 'tests/functional/qemu_test/testcase.py') diff --git a/tests/functional/qemu_test/testcase.py b/tests/functional/qemu_test/testcase.py index fceafb32b0..90ae59eb54 100644 --- a/tests/functional/qemu_test/testcase.py +++ b/tests/functional/qemu_test/testcase.py @@ -81,10 +81,12 @@ class QemuBaseTest(unittest.TestCase): res = unittest.main(module = None, testRunner = tr, exit = False, argv=["__dummy__", path]) for (test, message) in res.result.errors + res.result.failures: - print('More information on ' + test.id() + ' could be found here:' - '\n %s' % test.log_filename, file=sys.stderr) - if hasattr(test, 'console_log_name'): - print(' %s' % test.console_log_name, file=sys.stderr) + + if hasattr(test, "log_filename"): + print('More information on ' + test.id() + ' could be found here:' + '\n %s' % test.log_filename, file=sys.stderr) + if hasattr(test, 'console_log_name'): + print(' %s' % test.console_log_name, file=sys.stderr) sys.exit(not res.result.wasSuccessful()) -- cgit 1.4.1