diff options
Diffstat (limited to 'meta/lib/oeqa/utils')
| -rw-r--r-- | meta/lib/oeqa/utils/__init__.py | 60 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/buildproject.py | 22 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/commands.py | 199 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/decorators.py | 4 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/dump.py | 57 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/ftools.py | 4 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/git.py | 4 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/gitarchive.py | 237 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/httpserver.py | 43 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/logparser.py | 258 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/metadata.py | 38 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/network.py | 8 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/nfs.py | 39 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/package_manager.py | 21 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/qemurunner.py | 644 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/qemutinyrunner.py | 26 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/sshcontrol.py | 16 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/subprocesstweak.py | 3 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/targetbuild.py | 25 | ||||
| -rw-r--r-- | meta/lib/oeqa/utils/testexport.py | 4 |
20 files changed, 1253 insertions, 459 deletions
diff --git a/meta/lib/oeqa/utils/__init__.py b/meta/lib/oeqa/utils/__init__.py index 485de031a9..6d1ec4cb99 100644 --- a/meta/lib/oeqa/utils/__init__.py +++ b/meta/lib/oeqa/utils/__init__.py @@ -1,8 +1,10 @@ +# +# SPDX-License-Identifier: MIT +# # Enable other layers to have modules in the same named directory from pkgutil import extend_path __path__ = extend_path(__path__, __name__) - # Borrowed from CalledProcessError class CommandError(Exception): @@ -41,28 +43,48 @@ def make_logger_bitbake_compatible(logger): import logging """ - Bitbake logger redifines debug() in order to - set a level within debug, this breaks compatibility - with vainilla logging, so we neeed to redifine debug() - method again also add info() method with INFO + 1 level. + We need to raise the log level of the info output so unittest + messages are visible on the console. """ - def _bitbake_log_debug(*args, **kwargs): - lvl = logging.DEBUG - - if isinstance(args[0], int): - lvl = args[0] - msg = args[1] - args = args[2:] - else: - msg = args[0] - args = args[1:] - - logger.log(lvl, msg, *args, **kwargs) - def _bitbake_log_info(msg, *args, **kwargs): logger.log(logging.INFO + 1, msg, *args, **kwargs) - logger.debug = _bitbake_log_debug logger.info = _bitbake_log_info return logger + +def load_test_components(logger, executor): + import sys + import os + import importlib + + from oeqa.core.context import OETestContextExecutor + + components = {} + + for path in sys.path: + base_dir = os.path.join(path, 'oeqa') + if os.path.exists(base_dir) and os.path.isdir(base_dir): + for file in os.listdir(base_dir): + comp_name = file + comp_context = os.path.join(base_dir, file, 'context.py') + if os.path.exists(comp_context): + comp_plugin = importlib.import_module('oeqa.%s.%s' % \ + (comp_name, 'context')) + try: + if not issubclass(comp_plugin._executor_class, + OETestContextExecutor): + raise TypeError("Component %s in %s, _executor_class "\ + "isn't derived from OETestContextExecutor."\ + % (comp_name, comp_context)) + + if comp_plugin._executor_class._script_executor \ + != executor: + continue + + components[comp_name] = comp_plugin._executor_class() + except AttributeError: + raise AttributeError("Component %s in %s don't have "\ + "_executor_class defined." % (comp_name, comp_context)) + + return components diff --git a/meta/lib/oeqa/utils/buildproject.py b/meta/lib/oeqa/utils/buildproject.py index fc8879cfb8..dfb9661868 100644 --- a/meta/lib/oeqa/utils/buildproject.py +++ b/meta/lib/oeqa/utils/buildproject.py @@ -1,6 +1,8 @@ +# # Copyright (C) 2013-2016 Intel Corporation # -# Released under the MIT license (see COPYING.MIT) +# SPDX-License-Identifier: MIT +# # Provides a class for automating build tests for projects @@ -8,22 +10,30 @@ import os import re import subprocess import shutil +import tempfile from abc import ABCMeta, abstractmethod class BuildProject(metaclass=ABCMeta): - def __init__(self, uri, foldername=None, tmpdir="/tmp/", dl_dir=None): + def __init__(self, uri, foldername=None, tmpdir=None, dl_dir=None): self.uri = uri self.archive = os.path.basename(uri) - self.localarchive = os.path.join(tmpdir,self.archive) + self.tempdirobj = None + if not tmpdir: + self.tempdirobj = tempfile.TemporaryDirectory(prefix='buildproject-') + tmpdir = self.tempdirobj.name + self.localarchive = os.path.join(tmpdir, self.archive) self.dl_dir = dl_dir if foldername: self.fname = foldername else: self.fname = re.sub(r'\.tar\.bz2$|\.tar\.gz$|\.tar\.xz$', '', self.archive) + self.needclean = False # Download self.archive to self.localarchive def _download_archive(self): + + self.needclean = True if self.dl_dir and os.path.exists(os.path.join(self.dl_dir, self.archive)): shutil.copyfile(os.path.join(self.dl_dir, self.archive), self.localarchive) return @@ -48,5 +58,9 @@ class BuildProject(metaclass=ABCMeta): return self._run('cd %s; make install %s' % (self.targetdir, install_args)) def clean(self): + if self.tempdirobj: + self.tempdirobj.cleanup() + if not self.needclean: + return self._run('rm -rf %s' % self.targetdir) - subprocess.call('rm -f %s' % self.localarchive, shell=True) + subprocess.check_call('rm -f %s' % self.localarchive, shell=True) diff --git a/meta/lib/oeqa/utils/commands.py b/meta/lib/oeqa/utils/commands.py index 82c5908e9c..024261410e 100644 --- a/meta/lib/oeqa/utils/commands.py +++ b/meta/lib/oeqa/utils/commands.py @@ -1,6 +1,8 @@ +# # Copyright (c) 2013-2014 Intel Corporation # -# Released under the MIT license (see COPYING.MIT) +# SPDX-License-Identifier: MIT +# # DESCRIPTION # This module is mainly used by scripts/oe-selftest and modules under meta/oeqa/selftest @@ -13,6 +15,7 @@ import sys import signal import subprocess import threading +import time import logging from oeqa.utils import CommandError from oeqa.utils import ftools @@ -25,7 +28,7 @@ except ImportError: pass class Command(object): - def __init__(self, command, bg=False, timeout=None, data=None, **options): + def __init__(self, command, bg=False, timeout=None, data=None, output_log=None, **options): self.defaultopts = { "stdout": subprocess.PIPE, @@ -48,41 +51,108 @@ class Command(object): self.options.update(options) self.status = None + # We collect chunks of output before joining them at the end. + self._output_chunks = [] + self._error_chunks = [] self.output = None self.error = None - self.thread = None + self.threads = [] + self.output_log = output_log self.log = logging.getLogger("utils.commands") def run(self): self.process = subprocess.Popen(self.cmd, **self.options) - def commThread(): - self.output, self.error = self.process.communicate(self.data) - - self.thread = threading.Thread(target=commThread) - self.thread.start() + def readThread(output, stream, logfunc): + if logfunc: + for line in stream: + output.append(line) + logfunc(line.decode("utf-8", errors='replace').rstrip()) + else: + output.append(stream.read()) + + def readStderrThread(): + readThread(self._error_chunks, self.process.stderr, self.output_log.error if self.output_log else None) + + def readStdoutThread(): + readThread(self._output_chunks, self.process.stdout, self.output_log.info if self.output_log else None) + + def writeThread(): + try: + self.process.stdin.write(self.data) + self.process.stdin.close() + except OSError as ex: + # It's not an error when the command does not consume all + # of our data. subprocess.communicate() also ignores that. + if ex.errno != EPIPE: + raise + + # We write in a separate thread because then we can read + # without worrying about deadlocks. The additional thread is + # expected to terminate by itself and we mark it as a daemon, + # so even it should happen to not terminate for whatever + # reason, the main process will still exit, which will then + # kill the write thread. + if self.data: + thread = threading.Thread(target=writeThread, daemon=True) + thread.start() + self.threads.append(thread) + if self.process.stderr: + thread = threading.Thread(target=readStderrThread) + thread.start() + self.threads.append(thread) + if self.output_log: + self.output_log.info('Running: %s' % self.cmd) + thread = threading.Thread(target=readStdoutThread) + thread.start() + self.threads.append(thread) self.log.debug("Running command '%s'" % self.cmd) if not self.bg: - self.thread.join(self.timeout) + if self.timeout is None: + for thread in self.threads: + thread.join() + else: + deadline = time.time() + self.timeout + for thread in self.threads: + timeout = deadline - time.time() + if timeout < 0: + timeout = 0 + thread.join(timeout) self.stop() def stop(self): - if self.thread.isAlive(): - self.process.terminate() + for thread in self.threads: + if thread.is_alive(): + self.process.terminate() # let's give it more time to terminate gracefully before killing it - self.thread.join(5) - if self.thread.isAlive(): + thread.join(5) + if thread.is_alive(): self.process.kill() - self.thread.join() + thread.join() - if not self.output: - self.output = "" - else: - self.output = self.output.decode("utf-8", errors='replace').rstrip() - self.status = self.process.poll() + def finalize_output(data): + if not data: + data = "" + else: + data = b"".join(data) + data = data.decode("utf-8", errors='replace').rstrip() + return data + + self.output = finalize_output(self._output_chunks) + self._output_chunks = None + # self.error used to be a byte string earlier, probably unintentionally. + # Now it is a normal string, just like self.output. + self.error = finalize_output(self._error_chunks) + self._error_chunks = None + # At this point we know that the process has closed stdout/stderr, so + # it is safe and necessary to wait for the actual process completion. + self.status = self.process.wait() + self.process.stdout.close() + if self.process.stderr: + self.process.stderr.close() self.log.debug("Command '%s' returned %d as exit code." % (self.cmd, self.status)) # logging the complete output is insane @@ -97,7 +167,8 @@ class Result(object): pass -def runCmd(command, ignore_status=False, timeout=None, assert_error=True, native_sysroot=None, **options): +def runCmd(command, ignore_status=False, timeout=None, assert_error=True, sync=True, + native_sysroot=None, limit_exc_output=0, output_log=None, **options): result = Result() if native_sysroot: @@ -107,9 +178,18 @@ def runCmd(command, ignore_status=False, timeout=None, assert_error=True, native nenv['PATH'] = extra_paths + ':' + nenv.get('PATH', '') options['env'] = nenv - cmd = Command(command, timeout=timeout, **options) + cmd = Command(command, timeout=timeout, output_log=output_log, **options) cmd.run() + # tests can be heavy on IO and if bitbake can't write out its caches, we see timeouts. + # call sync around the tests to ensure the IO queue doesn't get too large, taking any IO + # hit here rather than in bitbake shutdown. + if sync: + p = os.environ['PATH'] + os.environ['PATH'] = "/usr/bin:/bin:/usr/sbin:/sbin:" + p + os.system("sync") + os.environ['PATH'] = p + result.command = command result.status = cmd.status result.output = cmd.output @@ -117,15 +197,21 @@ def runCmd(command, ignore_status=False, timeout=None, assert_error=True, native result.pid = cmd.process.pid if result.status and not ignore_status: + exc_output = result.output + if limit_exc_output > 0: + split = result.output.splitlines() + if len(split) > limit_exc_output: + exc_output = "\n... (last %d lines of output)\n" % limit_exc_output + \ + '\n'.join(split[-limit_exc_output:]) if assert_error: - raise AssertionError("Command '%s' returned non-zero exit status %d:\n%s" % (command, result.status, result.output)) + raise AssertionError("Command '%s' returned non-zero exit status %d:\n%s" % (command, result.status, exc_output)) else: - raise CommandError(result.status, command, result.output) + raise CommandError(result.status, command, exc_output) return result -def bitbake(command, ignore_status=False, timeout=None, postconfig=None, **options): +def bitbake(command, ignore_status=False, timeout=None, postconfig=None, output_log=None, **options): if postconfig: postconfig_file = os.path.join(os.environ.get('BUILDDIR'), 'oeqa-post.conf') @@ -140,7 +226,7 @@ def bitbake(command, ignore_status=False, timeout=None, postconfig=None, **optio cmd = [ "bitbake" ] + [a for a in (command + extra_args.split(" ")) if a not in [""]] try: - return runCmd(cmd, ignore_status, timeout, **options) + return runCmd(cmd, ignore_status, timeout, output_log=output_log, **options) finally: if postconfig: os.remove(postconfig_file) @@ -157,8 +243,8 @@ def get_bb_vars(variables=None, target=None, postconfig=None): bbenv = get_bb_env(target, postconfig=postconfig) if variables is not None: - variables = variables.copy() - var_re = re.compile(r'^(export )?(?P<var>\w+)="(?P<value>.*)"$') + variables = list(variables) + var_re = re.compile(r'^(export )?(?P<var>\w+(_.*)?)="(?P<value>.*)"$') unset_re = re.compile(r'^unset (?P<var>\w+)$') lastline = None values = {} @@ -215,62 +301,65 @@ def create_temp_layer(templayerdir, templayername, priority=999, recipepathspec= f.write('BBFILE_PATTERN_%s = "^${LAYERDIR}/"\n' % templayername) f.write('BBFILE_PRIORITY_%s = "%d"\n' % (templayername, priority)) f.write('BBFILE_PATTERN_IGNORE_EMPTY_%s = "1"\n' % templayername) - + f.write('LAYERSERIES_COMPAT_%s = "${LAYERSERIES_COMPAT_core}"\n' % templayername) @contextlib.contextmanager -def runqemu(pn, ssh=True, runqemuparams='', image_fstype=None): +def runqemu(pn, ssh=True, runqemuparams='', image_fstype=None, launch_cmd=None, qemuparams=None, overrides={}, discard_writes=True): + """ + launch_cmd means directly run the command, don't need set rootfs or env vars. + """ import bb.tinfoil import bb.build + # Need a non-'BitBake' logger to capture the runner output + targetlogger = logging.getLogger('TargetRunner') + targetlogger.setLevel(logging.DEBUG) + handler = logging.StreamHandler(sys.stdout) + targetlogger.addHandler(handler) + tinfoil = bb.tinfoil.Tinfoil() tinfoil.prepare(config_only=False, quiet=True) try: tinfoil.logger.setLevel(logging.WARNING) import oeqa.targetcontrol - tinfoil.config_data.setVar("TEST_LOG_DIR", "${WORKDIR}/testimage") - tinfoil.config_data.setVar("TEST_QEMUBOOT_TIMEOUT", "1000") recipedata = tinfoil.parse_recipe(pn) + recipedata.setVar("TEST_LOG_DIR", "${WORKDIR}/testimage") + recipedata.setVar("TEST_QEMUBOOT_TIMEOUT", "1000") + # Tell QemuTarget() whether need find rootfs/kernel or not + if launch_cmd: + recipedata.setVar("FIND_ROOTFS", '0') + else: + recipedata.setVar("FIND_ROOTFS", '1') + + for key, value in overrides.items(): + recipedata.setVar(key, value) - # The QemuRunner log is saved out, but we need to ensure it is at the right - # log level (and then ensure that since it's a child of the BitBake logger, - # we disable propagation so we don't then see the log events on the console) - logger = logging.getLogger('BitBake.QemuRunner') - logger.setLevel(logging.DEBUG) - logger.propagate = False logdir = recipedata.getVar("TEST_LOG_DIR") - qemu = oeqa.targetcontrol.QemuTarget(recipedata, image_fstype) + qemu = oeqa.targetcontrol.QemuTarget(recipedata, targetlogger, image_fstype) finally: # We need to shut down tinfoil early here in case we actually want # to run tinfoil-using utilities with the running QEMU instance. # Luckily QemuTarget doesn't need it after the constructor. tinfoil.shutdown() - # Setup bitbake logger as console handler is removed by tinfoil.shutdown - bblogger = logging.getLogger('BitBake') - bblogger.setLevel(logging.INFO) - console = logging.StreamHandler(sys.stdout) - bbformat = bb.msg.BBLogFormatter("%(levelname)s: %(message)s") - if sys.stdout.isatty(): - bbformat.enable_color() - console.setFormatter(bbformat) - bblogger.addHandler(console) - try: qemu.deploy() try: - qemu.start(ssh=ssh, runqemuparams=runqemuparams) - except bb.build.FuncFailed: - raise Exception('Failed to start QEMU - see the logs in %s' % logdir) + qemu.start(params=qemuparams, ssh=ssh, runqemuparams=runqemuparams, launch_cmd=launch_cmd, discard_writes=discard_writes) + except Exception as e: + msg = str(e) + '\nFailed to start QEMU - see the logs in %s' % logdir + if os.path.exists(qemu.qemurunnerlog): + with open(qemu.qemurunnerlog, 'r') as f: + msg = msg + "Qemurunner log output from %s:\n%s" % (qemu.qemurunnerlog, f.read()) + raise Exception(msg) yield qemu finally: - try: - qemu.stop() - except: - pass + targetlogger.removeHandler(handler) + qemu.stop() def updateEnv(env_file): """ diff --git a/meta/lib/oeqa/utils/decorators.py b/meta/lib/oeqa/utils/decorators.py index d876896921..aabf4110cb 100644 --- a/meta/lib/oeqa/utils/decorators.py +++ b/meta/lib/oeqa/utils/decorators.py @@ -1,6 +1,8 @@ +# # Copyright (C) 2013 Intel Corporation # -# Released under the MIT license (see COPYING.MIT) +# SPDX-License-Identifier: MIT +# # Some custom decorators that can be used by unittests # Most useful is skipUnlessPassed which can be used for diff --git a/meta/lib/oeqa/utils/dump.py b/meta/lib/oeqa/utils/dump.py index 5a7edc1a86..95a79a571c 100644 --- a/meta/lib/oeqa/utils/dump.py +++ b/meta/lib/oeqa/utils/dump.py @@ -1,5 +1,10 @@ +# +# SPDX-License-Identifier: MIT +# + import os import sys +import json import errno import datetime import itertools @@ -12,7 +17,8 @@ class BaseDumper(object): self.cmds = [] # Some testing doesn't inherit testimage, so it is needed # to set some defaults. - self.parent_dir = parent_dir or "/tmp/oe-saved-tests" + self.parent_dir = parent_dir + self.dump_dir = parent_dir dft_cmds = """ top -bn1 iostat -x -z -N -d -p ALL 20 2 ps -ef @@ -42,11 +48,13 @@ class BaseDumper(object): raise err self.dump_dir = dump_dir - def _write_dump(self, command, output): + def _construct_filename(self, command): if isinstance(self, HostDumper): prefix = "host" elif isinstance(self, TargetDumper): prefix = "target" + elif isinstance(self, MonitorDumper): + prefix = "qmp" else: prefix = "unknown" for i in itertools.count(): @@ -54,9 +62,17 @@ class BaseDumper(object): fullname = os.path.join(self.dump_dir, filename) if not os.path.exists(fullname): break - with open(fullname, 'w') as dump_file: - dump_file.write(output) + return fullname + def _write_dump(self, command, output): + fullname = self._construct_filename(command) + os.makedirs(os.path.dirname(fullname), exist_ok=True) + if isinstance(self, MonitorDumper): + with open(fullname, 'w') as json_file: + json.dump(output, json_file, indent=4) + else: + with open(fullname, 'w') as dump_file: + dump_file.write(output) class HostDumper(BaseDumper): """ Class to get dumps from the host running the tests """ @@ -67,8 +83,11 @@ class HostDumper(BaseDumper): def dump_host(self, dump_dir=""): if dump_dir: self.dump_dir = dump_dir + env = os.environ.copy() + env['PATH'] = '/usr/sbin:/sbin:/usr/bin:/bin' + env['COLUMNS'] = '9999' for cmd in self.cmds: - result = runCmd(cmd, ignore_status=True) + result = runCmd(cmd, ignore_status=True, env=env) self._write_dump(cmd.split()[0], result.output) class TargetDumper(BaseDumper): @@ -89,3 +108,31 @@ class TargetDumper(BaseDumper): except: print("Tried to dump info from target but " "serial console failed") + print("Failed CMD: %s" % (cmd)) + +class MonitorDumper(BaseDumper): + """ Class to get dumps via the Qemu Monitor, it only works with QemuRunner """ + + def __init__(self, cmds, parent_dir, runner): + super(MonitorDumper, self).__init__(cmds, parent_dir) + self.runner = runner + + def dump_monitor(self, dump_dir=""): + if self.runner is None: + return + if dump_dir: + self.dump_dir = dump_dir + for cmd in self.cmds: + cmd_name = cmd.split()[0] + try: + if len(cmd.split()) > 1: + cmd_args = cmd.split()[1] + if "%s" in cmd_args: + filename = self._construct_filename(cmd_name) + cmd_data = json.loads(cmd_args % (filename)) + output = self.runner.run_monitor(cmd_name, cmd_data) + else: + output = self.runner.run_monitor(cmd_name) + self._write_dump(cmd_name, output) + except Exception as e: + print("Failed to dump QMP CMD: %s with\nException: %s" % (cmd_name, e)) diff --git a/meta/lib/oeqa/utils/ftools.py b/meta/lib/oeqa/utils/ftools.py index a7233d4ca6..3093419cc7 100644 --- a/meta/lib/oeqa/utils/ftools.py +++ b/meta/lib/oeqa/utils/ftools.py @@ -1,3 +1,7 @@ +# +# SPDX-License-Identifier: MIT +# + import os import re import errno diff --git a/meta/lib/oeqa/utils/git.py b/meta/lib/oeqa/utils/git.py index e0cb3f0db2..ea35a766eb 100644 --- a/meta/lib/oeqa/utils/git.py +++ b/meta/lib/oeqa/utils/git.py @@ -1,7 +1,7 @@ # # Copyright (C) 2016 Intel Corporation # -# Released under the MIT license (see COPYING.MIT) +# SPDX-License-Identifier: MIT # """Git repository interactions""" import os @@ -64,7 +64,7 @@ class GitRepo(object): def rev_parse(self, revision): """Do git rev-parse""" try: - return self.run_cmd(['rev-parse', revision]) + return self.run_cmd(['rev-parse', '--verify', revision]) except GitError: # Revision does not exist return None diff --git a/meta/lib/oeqa/utils/gitarchive.py b/meta/lib/oeqa/utils/gitarchive.py new file mode 100644 index 0000000000..6e8040eb5c --- /dev/null +++ b/meta/lib/oeqa/utils/gitarchive.py @@ -0,0 +1,237 @@ +# +# Helper functions for committing data to git and pushing upstream +# +# Copyright (c) 2017, Intel Corporation. +# Copyright (c) 2019, Linux Foundation +# +# SPDX-License-Identifier: GPL-2.0-only +# + +import os +import re +import sys +from operator import attrgetter +from collections import namedtuple +from oeqa.utils.git import GitRepo, GitError + +class ArchiveError(Exception): + """Internal error handling of this script""" + +def format_str(string, fields): + """Format string using the given fields (dict)""" + try: + return string.format(**fields) + except KeyError as err: + raise ArchiveError("Unable to expand string '{}': unknown field {} " + "(valid fields are: {})".format( + string, err, ', '.join(sorted(fields.keys())))) + + +def init_git_repo(path, no_create, bare, log): + """Initialize local Git repository""" + path = os.path.abspath(path) + if os.path.isfile(path): + raise ArchiveError("Invalid Git repo at {}: path exists but is not a " + "directory".format(path)) + if not os.path.isdir(path) or not os.listdir(path): + if no_create: + raise ArchiveError("No git repo at {}, refusing to create " + "one".format(path)) + if not os.path.isdir(path): + try: + os.mkdir(path) + except (FileNotFoundError, PermissionError) as err: + raise ArchiveError("Failed to mkdir {}: {}".format(path, err)) + if not os.listdir(path): + log.info("Initializing a new Git repo at %s", path) + repo = GitRepo.init(path, bare) + try: + repo = GitRepo(path, is_topdir=True) + except GitError: + raise ArchiveError("Non-empty directory that is not a Git repository " + "at {}\nPlease specify an existing Git repository, " + "an empty directory or a non-existing directory " + "path.".format(path)) + return repo + + +def git_commit_data(repo, data_dir, branch, message, exclude, notes, log): + """Commit data into a Git repository""" + log.info("Committing data into to branch %s", branch) + tmp_index = os.path.join(repo.git_dir, 'index.oe-git-archive') + try: + # Create new tree object from the data + env_update = {'GIT_INDEX_FILE': tmp_index, + 'GIT_WORK_TREE': os.path.abspath(data_dir)} + repo.run_cmd('add .', env_update) + + # Remove files that are excluded + if exclude: + repo.run_cmd(['rm', '--cached'] + [f for f in exclude], env_update) + + tree = repo.run_cmd('write-tree', env_update) + + # Create new commit object from the tree + parent = repo.rev_parse(branch) + if not parent: + parent = repo.rev_parse("origin/" + branch) + git_cmd = ['commit-tree', tree, '-m', message] + if parent: + git_cmd += ['-p', parent] + commit = repo.run_cmd(git_cmd, env_update) + + # Create git notes + for ref, filename in notes: + ref = ref.format(branch_name=branch) + repo.run_cmd(['notes', '--ref', ref, 'add', + '-F', os.path.abspath(filename), commit]) + + # Update branch head + git_cmd = ['update-ref', 'refs/heads/' + branch, commit] + repo.run_cmd(git_cmd) + + # Update current HEAD, if we're on branch 'branch' + if not repo.bare and repo.get_current_branch() == branch: + log.info("Updating %s HEAD to latest commit", repo.top_dir) + repo.run_cmd('reset --hard') + + return commit + finally: + if os.path.exists(tmp_index): + os.unlink(tmp_index) + + +def expand_tag_strings(repo, name_pattern, msg_subj_pattern, msg_body_pattern, + keywords): + """Generate tag name and message, with support for running id number""" + keyws = keywords.copy() + # Tag number is handled specially: if not defined, we autoincrement it + if 'tag_number' not in keyws: + # Fill in all other fields than 'tag_number' + keyws['tag_number'] = '{tag_number}' + tag_re = format_str(name_pattern, keyws) + # Replace parentheses for proper regex matching + tag_re = tag_re.replace('(', '\(').replace(')', '\)') + '$' + # Inject regex group pattern for 'tag_number' + tag_re = tag_re.format(tag_number='(?P<tag_number>[0-9]{1,5})') + + keyws['tag_number'] = 0 + for existing_tag in repo.run_cmd('tag').splitlines(): + match = re.match(tag_re, existing_tag) + + if match and int(match.group('tag_number')) >= keyws['tag_number']: + keyws['tag_number'] = int(match.group('tag_number')) + 1 + + tag_name = format_str(name_pattern, keyws) + msg_subj= format_str(msg_subj_pattern.strip(), keyws) + msg_body = format_str(msg_body_pattern, keyws) + return tag_name, msg_subj + '\n\n' + msg_body + +def gitarchive(data_dir, git_dir, no_create, bare, commit_msg_subject, commit_msg_body, branch_name, no_tag, tagname, tag_msg_subject, tag_msg_body, exclude, notes, push, keywords, log): + + if not os.path.isdir(data_dir): + raise ArchiveError("Not a directory: {}".format(data_dir)) + + data_repo = init_git_repo(git_dir, no_create, bare, log) + + # Expand strings early in order to avoid getting into inconsistent + # state (e.g. no tag even if data was committed) + commit_msg = format_str(commit_msg_subject.strip(), keywords) + commit_msg += '\n\n' + format_str(commit_msg_body, keywords) + branch_name = format_str(branch_name, keywords) + tag_name = None + if not no_tag and tagname: + tag_name, tag_msg = expand_tag_strings(data_repo, tagname, + tag_msg_subject, + tag_msg_body, keywords) + + # Commit data + commit = git_commit_data(data_repo, data_dir, branch_name, + commit_msg, exclude, notes, log) + + # Create tag + if tag_name: + log.info("Creating tag %s", tag_name) + data_repo.run_cmd(['tag', '-a', '-m', tag_msg, tag_name, commit]) + + # Push data to remote + if push: + cmd = ['push', '--tags'] + # If no remote is given we push with the default settings from + # gitconfig + if push is not True: + notes_refs = ['refs/notes/' + ref.format(branch_name=branch_name) + for ref, _ in notes] + cmd.extend([push, branch_name] + notes_refs) + log.info("Pushing data to remote") + data_repo.run_cmd(cmd) + +# Container class for tester revisions +TestedRev = namedtuple('TestedRev', 'commit commit_number tags') + +def get_test_runs(log, repo, tag_name, **kwargs): + """Get a sorted list of test runs, matching given pattern""" + # First, get field names from the tag name pattern + field_names = [m.group(1) for m in re.finditer(r'{(\w+)}', tag_name)] + undef_fields = [f for f in field_names if f not in kwargs.keys()] + + # Fields for formatting tag name pattern + str_fields = dict([(f, '*') for f in field_names]) + str_fields.update(kwargs) + + # Get a list of all matching tags + tag_pattern = tag_name.format(**str_fields) + tags = repo.run_cmd(['tag', '-l', tag_pattern]).splitlines() + log.debug("Found %d tags matching pattern '%s'", len(tags), tag_pattern) + + # Parse undefined fields from tag names + str_fields = dict([(f, r'(?P<{}>[\w\-.()]+)'.format(f)) for f in field_names]) + str_fields['branch'] = r'(?P<branch>[\w\-.()/]+)' + str_fields['commit'] = '(?P<commit>[0-9a-f]{7,40})' + str_fields['commit_number'] = '(?P<commit_number>[0-9]{1,7})' + str_fields['tag_number'] = '(?P<tag_number>[0-9]{1,5})' + # escape parenthesis in fields in order to not messa up the regexp + fixed_fields = dict([(k, v.replace('(', r'\(').replace(')', r'\)')) for k, v in kwargs.items()]) + str_fields.update(fixed_fields) + tag_re = re.compile(tag_name.format(**str_fields)) + + # Parse fields from tags + revs = [] + for tag in tags: + m = tag_re.match(tag) + groups = m.groupdict() + revs.append([groups[f] for f in undef_fields] + [tag]) + + # Return field names and a sorted list of revs + return undef_fields, sorted(revs) + +def get_test_revs(log, repo, tag_name, **kwargs): + """Get list of all tested revisions""" + fields, runs = get_test_runs(log, repo, tag_name, **kwargs) + + revs = {} + commit_i = fields.index('commit') + commit_num_i = fields.index('commit_number') + for run in runs: + commit = run[commit_i] + commit_num = run[commit_num_i] + tag = run[-1] + if not commit in revs: + revs[commit] = TestedRev(commit, commit_num, [tag]) + else: + assert commit_num == revs[commit].commit_number, "Commit numbers do not match" + revs[commit].tags.append(tag) + + # Return in sorted table + revs = sorted(revs.values(), key=attrgetter('commit_number')) + log.debug("Found %d tested revisions:\n %s", len(revs), + "\n ".join(['{} ({})'.format(rev.commit_number, rev.commit) for rev in revs])) + return revs + +def rev_find(revs, attr, val): + """Search from a list of TestedRev""" + for i, rev in enumerate(revs): + if getattr(rev, attr) == val: + return i + raise ValueError("Unable to find '{}' value '{}'".format(attr, val)) + diff --git a/meta/lib/oeqa/utils/httpserver.py b/meta/lib/oeqa/utils/httpserver.py index 7d12331453..58d3c3b3f8 100644 --- a/meta/lib/oeqa/utils/httpserver.py +++ b/meta/lib/oeqa/utils/httpserver.py @@ -1,13 +1,17 @@ +# +# SPDX-License-Identifier: MIT +# + import http.server import multiprocessing import os +import traceback +import signal from socketserver import ThreadingMixIn class HTTPServer(ThreadingMixIn, http.server.HTTPServer): - def server_start(self, root_dir): - import signal - signal.signal(signal.SIGTERM, signal.SIG_DFL) + def server_start(self, root_dir, logger): os.chdir(root_dir) self.serve_forever() @@ -18,19 +22,40 @@ class HTTPRequestHandler(http.server.SimpleHTTPRequestHandler): class HTTPService(object): - def __init__(self, root_dir, host=''): + def __init__(self, root_dir, host='', port=0, logger=None): self.root_dir = root_dir self.host = host - self.port = 0 + self.port = port + self.logger = logger def start(self): + if not os.path.exists(self.root_dir): + self.logger.info("Not starting HTTPService for directory %s which doesn't exist" % (self.root_dir)) + return + self.server = HTTPServer((self.host, self.port), HTTPRequestHandler) if self.port == 0: self.port = self.server.server_port - self.process = multiprocessing.Process(target=self.server.server_start, args=[self.root_dir]) + self.process = multiprocessing.Process(target=self.server.server_start, args=[self.root_dir, self.logger]) + + # The signal handler from testimage.bbclass can cause deadlocks here + # if the HTTPServer is terminated before it can restore the standard + #signal behaviour + orig = signal.getsignal(signal.SIGTERM) + signal.signal(signal.SIGTERM, signal.SIG_DFL) self.process.start() + signal.signal(signal.SIGTERM, orig) + + if self.logger: + self.logger.info("Started HTTPService on %s:%s" % (self.host, self.port)) + def stop(self): - self.server.server_close() - self.process.terminate() - self.process.join() + if hasattr(self, "server"): + self.server.server_close() + if hasattr(self, "process"): + self.process.terminate() + self.process.join() + if self.logger: + self.logger.info("Stopped HTTPService on %s:%s" % (self.host, self.port)) + diff --git a/meta/lib/oeqa/utils/logparser.py b/meta/lib/oeqa/utils/logparser.py index b377dcd271..879aefca33 100644 --- a/meta/lib/oeqa/utils/logparser.py +++ b/meta/lib/oeqa/utils/logparser.py @@ -1,125 +1,161 @@ -#!/usr/bin/env python +# +# SPDX-License-Identifier: MIT +# import sys import os import re -from . import ftools - # A parser that can be used to identify weather a line is a test result or a section statement. -class Lparser(object): - - def __init__(self, test_0_pass_regex, test_0_fail_regex, section_0_begin_regex=None, section_0_end_regex=None, **kwargs): - # Initialize the arguments dictionary - if kwargs: - self.args = kwargs - else: - self.args = {} - - # Add the default args to the dictionary - self.args['test_0_pass_regex'] = test_0_pass_regex - self.args['test_0_fail_regex'] = test_0_fail_regex - if section_0_begin_regex: - self.args['section_0_begin_regex'] = section_0_begin_regex - if section_0_end_regex: - self.args['section_0_end_regex'] = section_0_end_regex - - self.test_possible_status = ['pass', 'fail', 'error'] - self.section_possible_status = ['begin', 'end'] - - self.initialized = False - - - # Initialize the parser with the current configuration - def init(self): - - # extra arguments can be added by the user to define new test and section categories. They must follow a pre-defined pattern: <type>_<category_name>_<status>_regex - self.test_argument_pattern = "^test_(.+?)_(%s)_regex" % '|'.join(map(str, self.test_possible_status)) - self.section_argument_pattern = "^section_(.+?)_(%s)_regex" % '|'.join(map(str, self.section_possible_status)) - - # Initialize the test and section regex dictionaries - self.test_regex = {} - self.section_regex ={} - - for arg, value in self.args.items(): - if not value: - raise Exception('The value of provided argument %s is %s. Should have a valid value.' % (key, value)) - is_test = re.search(self.test_argument_pattern, arg) - is_section = re.search(self.section_argument_pattern, arg) - if is_test: - if not is_test.group(1) in self.test_regex: - self.test_regex[is_test.group(1)] = {} - self.test_regex[is_test.group(1)][is_test.group(2)] = re.compile(value) - elif is_section: - if not is_section.group(1) in self.section_regex: - self.section_regex[is_section.group(1)] = {} - self.section_regex[is_section.group(1)][is_section.group(2)] = re.compile(value) - else: - # TODO: Make these call a traceback instead of a simple exception.. - raise Exception("The provided argument name does not correspond to any valid type. Please give one of the following types:\nfor tests: %s\nfor sections: %s" % (self.test_argument_pattern, self.section_argument_pattern)) - - self.initialized = True - - # Parse a line and return a tuple containing the type of result (test/section) and its category, status and name - def parse_line(self, line): - if not self.initialized: - raise Exception("The parser is not initialized..") - - for test_category, test_status_list in self.test_regex.items(): - for test_status, status_regex in test_status_list.items(): - test_name = status_regex.search(line) - if test_name: - return ['test', test_category, test_status, test_name.group(1)] - - for section_category, section_status_list in self.section_regex.items(): - for section_status, status_regex in section_status_list.items(): - section_name = status_regex.search(line) - if section_name: - return ['section', section_category, section_status, section_name.group(1)] - return None - - -class Result(object): - +class PtestParser(object): def __init__(self): - self.result_dict = {} - - def store(self, section, test, status): - if not section in self.result_dict: - self.result_dict[section] = [] - - self.result_dict[section].append((test, status)) - - # sort tests by the test name(the first element of the tuple), for each section. This can be helpful when using git to diff for changes by making sure they are always in the same order. - def sort_tests(self): - for package in self.result_dict: - sorted_results = sorted(self.result_dict[package], key=lambda tup: tup[0]) - self.result_dict[package] = sorted_results + self.results = {} + self.sections = {} + + def parse(self, logfile): + test_regex = {} + test_regex['PASSED'] = re.compile(r"^PASS:(.+)") + test_regex['FAILED'] = re.compile(r"^FAIL:([^(]+)") + test_regex['SKIPPED'] = re.compile(r"^SKIP:(.+)") + + section_regex = {} + section_regex['begin'] = re.compile(r"^BEGIN: .*/(.+)/ptest") + section_regex['end'] = re.compile(r"^END: .*/(.+)/ptest") + section_regex['duration'] = re.compile(r"^DURATION: (.+)") + section_regex['exitcode'] = re.compile(r"^ERROR: Exit status is (.+)") + section_regex['timeout'] = re.compile(r"^TIMEOUT: .*/(.+)/ptest") + + # Cache markers so we don't take the re.search() hit all the time. + markers = ("PASS:", "FAIL:", "SKIP:", "BEGIN:", "END:", "DURATION:", "ERROR: Exit", "TIMEOUT:") + + def newsection(): + return { 'name': "No-section", 'log': [] } + + current_section = newsection() + + with open(logfile, errors='replace') as f: + for line in f: + if not line.startswith(markers): + current_section['log'].append(line) + continue + + result = section_regex['begin'].search(line) + if result: + current_section['name'] = result.group(1) + continue + + result = section_regex['end'].search(line) + if result: + if current_section['name'] != result.group(1): + bb.warn("Ptest END log section mismatch %s vs. %s" % (current_section['name'], result.group(1))) + if current_section['name'] in self.sections: + bb.warn("Ptest duplicate section for %s" % (current_section['name'])) + self.sections[current_section['name']] = current_section + del self.sections[current_section['name']]['name'] + current_section = newsection() + continue + + result = section_regex['timeout'].search(line) + if result: + if current_section['name'] != result.group(1): + bb.warn("Ptest TIMEOUT log section mismatch %s vs. %s" % (current_section['name'], result.group(1))) + current_section['timeout'] = True + continue + + for t in ['duration', 'exitcode']: + result = section_regex[t].search(line) + if result: + current_section[t] = result.group(1) + continue + + current_section['log'].append(line) + + for t in test_regex: + result = test_regex[t].search(line) + if result: + if current_section['name'] not in self.results: + self.results[current_section['name']] = {} + self.results[current_section['name']][result.group(1).strip()] = t + + # Python performance for repeatedly joining long strings is poor, do it all at once at the end. + # For 2.1 million lines in a log this reduces 18 hours to 12s. + for section in self.sections: + self.sections[section]['log'] = "".join(self.sections[section]['log']) + + return self.results, self.sections # Log the results as files. The file name is the section name and the contents are the tests in that section. - def log_as_files(self, target_dir, test_status): - status_regex = re.compile('|'.join(map(str, test_status))) - if not type(test_status) == type([]): - raise Exception("test_status should be a list. Got " + str(test_status) + " instead.") + def results_as_files(self, target_dir): if not os.path.exists(target_dir): raise Exception("Target directory does not exist: %s" % target_dir) - for section, test_results in self.result_dict.items(): - prefix = '' - for x in test_status: - prefix +=x+'.' - if (section != ''): - prefix += section + for section in self.results: + prefix = 'No-section' + if section: + prefix = section section_file = os.path.join(target_dir, prefix) # purge the file contents if it exists - open(section_file, 'w').close() - for test_result in test_results: - (test_name, status) = test_result - # we log only the tests with status in the test_status list - match_status = status_regex.search(status) - if match_status: - ftools.append_file(section_file, status + ": " + test_name) - - # Not yet implemented! - def log_to_lava(self): - pass + with open(section_file, 'w') as f: + for test_name in sorted(self.results[section]): + status = self.results[section][test_name] + f.write(status + ": " + test_name + "\n") + + +# ltp log parsing +class LtpParser(object): + def __init__(self): + self.results = {} + self.section = {'duration': "", 'log': ""} + + def parse(self, logfile): + test_regex = {} + test_regex['PASSED'] = re.compile(r"PASS") + test_regex['FAILED'] = re.compile(r"FAIL") + test_regex['SKIPPED'] = re.compile(r"SKIP") + + with open(logfile, errors='replace') as f: + for line in f: + for t in test_regex: + result = test_regex[t].search(line) + if result: + self.results[line.split()[0].strip()] = t + + for test in self.results: + result = self.results[test] + self.section['log'] = self.section['log'] + ("%s: %s\n" % (result.strip()[:-2], test.strip())) + + return self.results, self.section + + +# ltp Compliance log parsing +class LtpComplianceParser(object): + def __init__(self): + self.results = {} + self.section = {'duration': "", 'log': ""} + + def parse(self, logfile): + test_regex = {} + test_regex['FAILED'] = re.compile(r"FAIL") + + section_regex = {} + section_regex['test'] = re.compile(r"^Executing") + + with open(logfile, errors='replace') as f: + name = logfile + result = "PASSED" + for line in f: + regex_result = section_regex['test'].search(line) + if regex_result: + name = line.split()[1].strip() + + regex_result = test_regex['FAILED'].search(line) + if regex_result: + result = "FAILED" + self.results[name] = result + + for test in self.results: + result = self.results[test] + print (self.results) + self.section['log'] = self.section['log'] + ("%s: %s\n" % (result.strip()[:-2], test.strip())) + + return self.results, self.section diff --git a/meta/lib/oeqa/utils/metadata.py b/meta/lib/oeqa/utils/metadata.py index cb81155e54..8013aa684d 100644 --- a/meta/lib/oeqa/utils/metadata.py +++ b/meta/lib/oeqa/utils/metadata.py @@ -1,6 +1,6 @@ # Copyright (C) 2016 Intel Corporation # -# Released under the MIT license (see COPYING.MIT) +# SPDX-License-Identifier: MIT # # Functions to get metadata from the testing host used # for analytics of test results. @@ -10,19 +10,9 @@ from collections.abc import MutableMapping from xml.dom.minidom import parseString from xml.etree.ElementTree import Element, tostring +from oe.lsb import get_os_release from oeqa.utils.commands import runCmd, get_bb_vars -def get_os_release(): - """Get info from /etc/os-release as a dict""" - data = OrderedDict() - os_release_file = '/etc/os-release' - if not os.path.exists(os_release_file): - return None - with open(os_release_file) as fobj: - for line in fobj: - key, value = line.split('=', 1) - data[key.strip().lower()] = value.strip().strip('"') - return data def metadata_from_bb(): """ Returns test's metadata as OrderedDict. @@ -45,9 +35,9 @@ def metadata_from_bb(): os_release = get_os_release() if os_release: info_dict['host_distro'] = OrderedDict() - for key in ('id', 'version_id', 'pretty_name'): + for key in ('ID', 'VERSION_ID', 'PRETTY_NAME'): if key in os_release: - info_dict['host_distro'][key] = os_release[key] + info_dict['host_distro'][key.lower()] = os_release[key] info_dict['layers'] = get_layers(data_dict['BBLAYERS']) info_dict['bitbake'] = git_rev_info(os.path.dirname(bb.__file__)) @@ -68,9 +58,25 @@ def metadata_from_data_store(d): def git_rev_info(path): """Get git revision information as a dict""" - from git import Repo, InvalidGitRepositoryError, NoSuchPathError - info = OrderedDict() + + try: + from git import Repo, InvalidGitRepositoryError, NoSuchPathError + except ImportError: + import subprocess + try: + info['branch'] = subprocess.check_output(["git", "rev-parse", "--abbrev-ref", "HEAD"], cwd=path).decode('utf-8').strip() + except subprocess.CalledProcessError: + pass + try: + info['commit'] = subprocess.check_output(["git", "rev-parse", "HEAD"], cwd=path).decode('utf-8').strip() + except subprocess.CalledProcessError: + pass + try: + info['commit_count'] = int(subprocess.check_output(["git", "rev-list", "--count", "HEAD"], cwd=path).decode('utf-8').strip()) + except subprocess.CalledProcessError: + pass + return info try: repo = Repo(path, search_parent_directories=True) except (InvalidGitRepositoryError, NoSuchPathError): diff --git a/meta/lib/oeqa/utils/network.py b/meta/lib/oeqa/utils/network.py index 2768f6c5db..59d01723a1 100644 --- a/meta/lib/oeqa/utils/network.py +++ b/meta/lib/oeqa/utils/network.py @@ -1,7 +1,11 @@ +# +# SPDX-License-Identifier: MIT +# + import socket -def get_free_port(): - s = socket.socket(socket.AF_INET, socket.SOCK_STREAM) +def get_free_port(udp = False): + s = socket.socket(socket.AF_INET, socket.SOCK_STREAM if not udp else socket.SOCK_DGRAM) s.bind(('', 0)) addr = s.getsockname() s.close() diff --git a/meta/lib/oeqa/utils/nfs.py b/meta/lib/oeqa/utils/nfs.py new file mode 100644 index 0000000000..a37686c914 --- /dev/null +++ b/meta/lib/oeqa/utils/nfs.py @@ -0,0 +1,39 @@ +# SPDX-License-Identifier: MIT +import os +import sys +import tempfile +import contextlib +import socket +from oeqa.utils.commands import bitbake, get_bb_var, Command +from oeqa.utils.network import get_free_port + +@contextlib.contextmanager +def unfs_server(directory, logger = None): + unfs_sysroot = get_bb_var("RECIPE_SYSROOT_NATIVE", "unfs3-native") + if not os.path.exists(os.path.join(unfs_sysroot, "usr", "bin", "unfsd")): + # build native tool + bitbake("unfs3-native -c addto_recipe_sysroot") + + exports = None + cmd = None + try: + # create the exports file + with tempfile.NamedTemporaryFile(delete = False) as exports: + exports.write("{0} (rw,no_root_squash,no_all_squash,insecure)\n".format(directory).encode()) + + # find some ports for the server + nfsport, mountport = get_free_port(udp = True), get_free_port(udp = True) + + nenv = dict(os.environ) + nenv['PATH'] = "{0}/sbin:{0}/usr/sbin:{0}/usr/bin:".format(unfs_sysroot) + nenv.get('PATH', '') + cmd = Command(["unfsd", "-d", "-p", "-N", "-e", exports.name, "-n", str(nfsport), "-m", str(mountport)], + bg = True, env = nenv, output_log = logger) + cmd.run() + yield nfsport, mountport + finally: + if cmd is not None: + cmd.stop() + if exports is not None: + # clean up exports file + os.unlink(exports.name) + diff --git a/meta/lib/oeqa/utils/package_manager.py b/meta/lib/oeqa/utils/package_manager.py index 724afb2b5e..6b67f22fdd 100644 --- a/meta/lib/oeqa/utils/package_manager.py +++ b/meta/lib/oeqa/utils/package_manager.py @@ -1,3 +1,7 @@ +# +# SPDX-License-Identifier: MIT +# + import os import json import shutil @@ -8,26 +12,31 @@ def get_package_manager(d, root_path): """ Returns an OE package manager that can install packages in root_path. """ - from oe.package_manager import RpmPM, OpkgPM, DpkgPM + from oe.package_manager.rpm import RpmPM + from oe.package_manager.ipk import OpkgPM + from oe.package_manager.deb import DpkgPM pkg_class = d.getVar("IMAGE_PKGTYPE") if pkg_class == "rpm": pm = RpmPM(d, root_path, - d.getVar('TARGET_VENDOR')) + d.getVar('TARGET_VENDOR'), + filterbydependencies=False) pm.create_configs() elif pkg_class == "ipk": pm = OpkgPM(d, root_path, d.getVar("IPKGCONF_TARGET"), - d.getVar("ALL_MULTILIB_PACKAGE_ARCHS")) + d.getVar("ALL_MULTILIB_PACKAGE_ARCHS"), + filterbydependencies=False) elif pkg_class == "deb": pm = DpkgPM(d, root_path, d.getVar('PACKAGE_ARCHS'), - d.getVar('DPKG_ARCH')) + d.getVar('DPKG_ARCH'), + filterbydependencies=False) pm.write_index() pm.update() @@ -108,7 +117,7 @@ def extract_packages(d, needed_packages): extract = package.get('extract', True) if extract: - #logger.debug(1, 'Extracting %s' % pkg) + #logger.debug('Extracting %s' % pkg) dst_dir = os.path.join(extracted_path, pkg) # Same package used for more than one test, # don't need to extract again. @@ -121,7 +130,7 @@ def extract_packages(d, needed_packages): shutil.rmtree(pkg_dir) else: - #logger.debug(1, 'Copying %s' % pkg) + #logger.debug('Copying %s' % pkg) _copy_package(d, pkg) def _extract_in_tmpdir(d, pkg): diff --git a/meta/lib/oeqa/utils/qemurunner.py b/meta/lib/oeqa/utils/qemurunner.py index 59dc11d00f..76296d50cd 100644 --- a/meta/lib/oeqa/utils/qemurunner.py +++ b/meta/lib/oeqa/utils/qemurunner.py @@ -1,6 +1,8 @@ +# # Copyright (C) 2013 Intel Corporation # -# Released under the MIT license (see COPYING.MIT) +# SPDX-License-Identifier: MIT +# # This module provides a class for starting qemu images using runqemu. # It's used by testimage.bbclass. @@ -17,11 +19,11 @@ import errno import string import threading import codecs -from oeqa.utils.dump import HostDumper - import logging -logger = logging.getLogger("BitBake.QemuRunner") -logger.addHandler(logging.StreamHandler()) +import tempfile +from oeqa.utils.dump import HostDumper +from collections import defaultdict +import importlib # Get Unicode non printable control chars control_range = list(range(0,32))+list(range(127,160)) @@ -31,16 +33,20 @@ re_control_char = re.compile('[%s]' % re.escape("".join(control_chars))) class QemuRunner: - def __init__(self, machine, rootfs, display, tmpdir, deploy_dir_image, logfile, boottime, dump_dir, dump_host_cmds, use_kvm): + def __init__(self, machine, rootfs, display, tmpdir, deploy_dir_image, logfile, boottime, dump_dir, dump_host_cmds, + use_kvm, logger, use_slirp=False, serial_ports=2, boot_patterns = defaultdict(str), use_ovmf=False, workdir=None, tmpfsdir=None): # Popen object for runqemu self.runqemu = None + self.runqemu_exited = False # pid of the qemu process that runqemu will start self.qemupid = None - # target ip - from the command line + # target ip - from the command line or runqemu output self.ip = None # host ip - where qemu is running self.server_ip = None + # target ip netmask + self.netmask = None self.machine = machine self.rootfs = rootfs @@ -52,9 +58,42 @@ class QemuRunner: self.logged = False self.thread = None self.use_kvm = use_kvm - - self.runqemutime = 60 + self.use_ovmf = use_ovmf + self.use_slirp = use_slirp + self.serial_ports = serial_ports + self.msg = '' + self.boot_patterns = boot_patterns + self.tmpfsdir = tmpfsdir + + self.runqemutime = 300 + if not workdir: + workdir = os.getcwd() + self.qemu_pidfile = workdir + '/pidfile_' + str(os.getpid()) self.host_dumper = HostDumper(dump_host_cmds, dump_dir) + self.monitorpipe = None + + self.logger = logger + # Whether we're expecting an exit and should show related errors + self.canexit = False + + # Enable testing other OS's + # Set commands for target communication, and default to Linux ALWAYS + # Other OS's or baremetal applications need to provide their + # own implementation passing it through QemuRunner's constructor + # or by passing them through TESTIMAGE_BOOT_PATTERNS[flag] + # provided variables, where <flag> is one of the mentioned below. + accepted_patterns = ['search_reached_prompt', 'send_login_user', 'search_login_succeeded', 'search_cmd_finished'] + default_boot_patterns = defaultdict(str) + # Default to the usual paterns used to communicate with the target + default_boot_patterns['search_reached_prompt'] = b' login:' + default_boot_patterns['send_login_user'] = 'root\n' + default_boot_patterns['search_login_succeeded'] = r"root@[a-zA-Z0-9\-]+:~#" + default_boot_patterns['search_cmd_finished'] = r"[a-zA-Z0-9]+@[a-zA-Z0-9\-]+:~#" + + # Only override patterns that were set e.g. login user TESTIMAGE_BOOT_PATTERNS[send_login_user] = "webserver\n" + for pattern in accepted_patterns: + if not self.boot_patterns[pattern]: + self.boot_patterns[pattern] = default_boot_patterns[pattern] def create_socket(self): try: @@ -63,7 +102,7 @@ class QemuRunner: sock.bind(("127.0.0.1",0)) sock.listen(2) port = sock.getsockname()[1] - logger.info("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port) + self.logger.debug("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port) return (sock, port) except socket.error: @@ -76,6 +115,7 @@ class QemuRunner: # because is possible to have control characters msg = msg.decode("utf-8", errors='ignore') msg = re_control_char.sub('', msg) + self.msg += msg with codecs.open(self.logfile, "a", encoding="utf-8") as f: f.write("%s" % msg) @@ -83,74 +123,123 @@ class QemuRunner: import fcntl fl = fcntl.fcntl(o, fcntl.F_GETFL) fcntl.fcntl(o, fcntl.F_SETFL, fl | os.O_NONBLOCK) - return os.read(o.fileno(), 1000000).decode("utf-8") + try: + return os.read(o.fileno(), 1000000).decode("utf-8") + except BlockingIOError: + return "" def handleSIGCHLD(self, signum, frame): if self.runqemu and self.runqemu.poll(): if self.runqemu.returncode: - logger.info('runqemu exited with code %d' % self.runqemu.returncode) - logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout)) + self.logger.error('runqemu exited with code %d' % self.runqemu.returncode) + self.logger.error('Output from runqemu:\n%s' % self.getOutput(self.runqemu.stdout)) self.stop() self._dump_host() - raise SystemExit - def start(self, qemuparams = None, get_ip = True, extra_bootparams = None, runqemuparams=''): + def start(self, qemuparams = None, get_ip = True, extra_bootparams = None, runqemuparams='', launch_cmd=None, discard_writes=True): + env = os.environ.copy() if self.display: - os.environ["DISPLAY"] = self.display + env["DISPLAY"] = self.display # Set this flag so that Qemu doesn't do any grabs as SDL grabs # interact badly with screensavers. - os.environ["QEMU_DONT_GRAB"] = "1" + env["QEMU_DONT_GRAB"] = "1" if not os.path.exists(self.rootfs): - logger.error("Invalid rootfs %s" % self.rootfs) + self.logger.error("Invalid rootfs %s" % self.rootfs) return False if not os.path.exists(self.tmpdir): - logger.error("Invalid TMPDIR path %s" % self.tmpdir) + self.logger.error("Invalid TMPDIR path %s" % self.tmpdir) return False else: - os.environ["OE_TMPDIR"] = self.tmpdir + env["OE_TMPDIR"] = self.tmpdir if not os.path.exists(self.deploy_dir_image): - logger.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image) + self.logger.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image) return False else: - os.environ["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image + env["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image + + if self.tmpfsdir: + env["RUNQEMU_TMPFS_DIR"] = self.tmpfsdir + + if not launch_cmd: + launch_cmd = 'runqemu %s' % ('snapshot' if discard_writes else '') + if self.use_kvm: + self.logger.debug('Using kvm for runqemu') + launch_cmd += ' kvm' + else: + self.logger.debug('Not using kvm for runqemu') + if not self.display: + launch_cmd += ' nographic' + if self.use_slirp: + launch_cmd += ' slirp' + if self.use_ovmf: + launch_cmd += ' ovmf' + launch_cmd += ' %s %s %s' % (runqemuparams, self.machine, self.rootfs) + + return self.launch(launch_cmd, qemuparams=qemuparams, get_ip=get_ip, extra_bootparams=extra_bootparams, env=env) + + def launch(self, launch_cmd, get_ip = True, qemuparams = None, extra_bootparams = None, env = None): + # use logfile to determine the recipe-sysroot-native path and + # then add in the site-packages path components and add that + # to the python sys.path so qmp.py can be found. + python_path = os.path.dirname(os.path.dirname(self.logfile)) + python_path += "/recipe-sysroot-native/usr/lib/qemu-python" + sys.path.append(python_path) + importlib.invalidate_caches() + try: + qmp = importlib.import_module("qmp") + except: + self.logger.error("qemurunner: qmp.py missing, please ensure it's installed") + return False + # Path relative to tmpdir used as cwd for qemu below to avoid unix socket path length issues + qmp_file = "." + next(tempfile._get_candidate_names()) + qmp_param = ' -S -qmp unix:./%s,server,wait' % (qmp_file) + qmp_port = self.tmpdir + "/" + qmp_file + # Create a second socket connection for debugging use, + # note this will NOT cause qemu to block waiting for the connection + qmp_file2 = "." + next(tempfile._get_candidate_names()) + qmp_param += ' -qmp unix:./%s,server,nowait' % (qmp_file2) + qmp_port2 = self.tmpdir + "/" + qmp_file2 + self.logger.info("QMP Available for connection at %s" % (qmp_port2)) try: - threadsock, threadport = self.create_socket() + if self.serial_ports >= 2: + self.threadsock, threadport = self.create_socket() self.server_socket, self.serverport = self.create_socket() except socket.error as msg: - logger.error("Failed to create listening socket: %s" % msg[1]) + self.logger.error("Failed to create listening socket: %s" % msg[1]) return False - - bootparams = 'console=tty1 console=ttyS0,115200n8 printk.time=1' + bootparams = ' printk.time=1' if extra_bootparams: bootparams = bootparams + ' ' + extra_bootparams - self.qemuparams = 'bootparams="{0}" qemuparams="-serial tcp:127.0.0.1:{1}"'.format(bootparams, threadport) - if not self.display: - self.qemuparams = 'nographic ' + self.qemuparams + # Ask QEMU to store the QEMU process PID in file, this way we don't have to parse running processes + # and analyze descendents in order to determine it. + if os.path.exists(self.qemu_pidfile): + os.remove(self.qemu_pidfile) + self.qemuparams = 'bootparams="{0}" qemuparams="-pidfile {1} {2}"'.format(bootparams, self.qemu_pidfile, qmp_param) + if qemuparams: self.qemuparams = self.qemuparams[:-1] + " " + qemuparams + " " + '\"' + if self.serial_ports >= 2: + launch_cmd += ' tcpserial=%s:%s %s' % (threadport, self.serverport, self.qemuparams) + else: + launch_cmd += ' tcpserial=%s %s' % (self.serverport, self.qemuparams) + self.origchldhandler = signal.getsignal(signal.SIGCHLD) signal.signal(signal.SIGCHLD, self.handleSIGCHLD) - launch_cmd = 'runqemu snapshot %s ' % runqemuparams - if self.use_kvm: - logger.info('Using kvm for runqemu') - launch_cmd += 'kvm ' - else: - logger.info('Not using kvm for runqemu') - launch_cmd += 'tcpserial=%s %s %s %s' % (self.serverport, self.machine, self.rootfs, self.qemuparams) - logger.info('launchcmd=%s'%(launch_cmd)) + self.logger.debug('launchcmd=%s'%(launch_cmd)) # FIXME: We pass in stdin=subprocess.PIPE here to work around stty # blocking at the end of the runqemu script when using this within # oe-selftest (this makes stty error out immediately). There ought # to be a proper fix but this will suffice for now. - self.runqemu = subprocess.Popen(launch_cmd, shell=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, stdin=subprocess.PIPE, preexec_fn=os.setpgrp) + self.runqemu = subprocess.Popen(launch_cmd, shell=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, stdin=subprocess.PIPE, preexec_fn=os.setpgrp, env=env, cwd=self.tmpdir) output = self.runqemu.stdout + launch_time = time.time() # # We need the preexec_fn above so that all runqemu processes can easily be killed @@ -176,133 +265,268 @@ class QemuRunner: r = os.fdopen(r) x = r.read() os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) - sys.exit(0) + os._exit(0) - logger.info("runqemu started, pid is %s" % self.runqemu.pid) - logger.info("waiting at most %s seconds for qemu pid" % self.runqemutime) + self.logger.debug("runqemu started, pid is %s" % self.runqemu.pid) + self.logger.debug("waiting at most %s seconds for qemu pid (%s)" % + (self.runqemutime, time.strftime("%D %H:%M:%S"))) endtime = time.time() + self.runqemutime while not self.is_alive() and time.time() < endtime: if self.runqemu.poll(): + if self.runqemu_exited: + self.logger.warning("runqemu during is_alive() test") + return False if self.runqemu.returncode: # No point waiting any longer - logger.info('runqemu exited with code %d' % self.runqemu.returncode) + self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode) self._dump_host() + self.logger.warning("Output from runqemu:\n%s" % self.getOutput(output)) self.stop() - logger.info("Output from runqemu:\n%s" % self.getOutput(output)) return False - time.sleep(1) - - if self.is_alive(): - logger.info("qemu started - qemu procces pid is %s" % self.qemupid) - if get_ip: - cmdline = '' - with open('/proc/%s/cmdline' % self.qemupid) as p: - cmdline = p.read() - # It is needed to sanitize the data received - # because is possible to have control characters - cmdline = re_control_char.sub('', cmdline) + time.sleep(0.5) + + if self.runqemu_exited: + self.logger.warning("runqemu after timeout") + + if self.runqemu.returncode: + self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode) + + if not self.is_alive(): + self.logger.error("Qemu pid didn't appear in %s seconds (%s)" % + (self.runqemutime, time.strftime("%D %H:%M:%S"))) + + qemu_pid = None + if os.path.isfile(self.qemu_pidfile): + with open(self.qemu_pidfile, 'r') as f: + qemu_pid = f.read().strip() + + self.logger.error("Status information, poll status: %s, pidfile exists: %s, pidfile contents %s, proc pid exists %s" + % (self.runqemu.poll(), os.path.isfile(self.qemu_pidfile), str(qemu_pid), os.path.exists("/proc/" + str(qemu_pid)))) + + # Dump all processes to help us to figure out what is going on... + ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,pri,ni,command '], stdout=subprocess.PIPE).communicate()[0] + processes = ps.decode("utf-8") + self.logger.debug("Running processes:\n%s" % processes) + self._dump_host() + op = self.getOutput(output) + self.stop() + if op: + self.logger.error("Output from runqemu:\n%s" % op) + else: + self.logger.error("No output from runqemu.\n") + return False + + # Create the client socket for the QEMU Monitor Control Socket + # This will allow us to read status from Qemu if the the process + # is still alive + self.logger.debug("QMP Initializing to %s" % (qmp_port)) + # chdir dance for path length issues with unix sockets + origpath = os.getcwd() + try: + os.chdir(os.path.dirname(qmp_port)) + try: + self.qmp = qmp.QEMUMonitorProtocol(os.path.basename(qmp_port)) + except OSError as msg: + self.logger.warning("Failed to initialize qemu monitor socket: %s File: %s" % (msg, msg.filename)) + return False + + self.logger.debug("QMP Connecting to %s" % (qmp_port)) + if not os.path.exists(qmp_port) and self.is_alive(): + self.logger.debug("QMP Port does not exist waiting for it to be created") + endtime = time.time() + self.runqemutime + while not os.path.exists(qmp_port) and self.is_alive() and time.time() < endtime: + self.logger.info("QMP port does not exist yet!") + time.sleep(0.5) + if not os.path.exists(qmp_port) and self.is_alive(): + self.logger.warning("QMP Port still does not exist but QEMU is alive") + return False + + try: + self.qmp.connect() + connect_time = time.time() + self.logger.info("QMP connected to QEMU at %s and took %s seconds" % + (time.strftime("%D %H:%M:%S"), + time.time() - launch_time)) + except OSError as msg: + self.logger.warning("Failed to connect qemu monitor socket: %s File: %s" % (msg, msg.filename)) + return False + except qmp.QMPConnectError as msg: + self.logger.warning("Failed to communicate with qemu monitor: %s" % (msg)) + return False + finally: + os.chdir(origpath) + + # We worry that mmap'd libraries may cause page faults which hang the qemu VM for periods + # causing failures. Before we "start" qemu, read through it's mapped files to try and + # ensure we don't hit page faults later + mapdir = "/proc/" + str(self.qemupid) + "/map_files/" + try: + for f in os.listdir(mapdir): try: - ips = re.findall("((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1]) - if not ips or len(ips) != 3: - raise ValueError - else: - self.ip = ips[0] - self.server_ip = ips[1] - except (IndexError, ValueError): - logger.info("Couldn't get ip from qemu process arguments! Here is the qemu command line used:\n%s\nand output from runqemu:\n%s" % (cmdline, self.getOutput(output))) + linktarget = os.readlink(os.path.join(mapdir, f)) + if not linktarget.startswith("/") or linktarget.startswith("/dev") or "deleted" in linktarget: + continue + with open(linktarget, "rb") as readf: + data = True + while data: + data = readf.read(4096) + except FileNotFoundError: + continue + # Centos7 doesn't allow us to read /map_files/ + except PermissionError: + pass + + # Release the qemu process to continue running + self.run_monitor('cont') + self.logger.info("QMP released QEMU at %s and took %s seconds from connect" % + (time.strftime("%D %H:%M:%S"), + time.time() - connect_time)) + + # We are alive: qemu is running + out = self.getOutput(output) + netconf = False # network configuration is not required by default + self.logger.debug("qemu started in %s seconds - qemu procces pid is %s (%s)" % + (time.time() - (endtime - self.runqemutime), + self.qemupid, time.strftime("%D %H:%M:%S"))) + cmdline = '' + if get_ip: + with open('/proc/%s/cmdline' % self.qemupid) as p: + cmdline = p.read() + # It is needed to sanitize the data received + # because is possible to have control characters + cmdline = re_control_char.sub(' ', cmdline) + try: + if self.use_slirp: + tcp_ports = cmdline.split("hostfwd=tcp::")[1] + host_port = tcp_ports[:tcp_ports.find('-')] + self.ip = "localhost:%s" % host_port + else: + ips = re.findall(r"((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1]) + self.ip = ips[0] + self.server_ip = ips[1] + self.logger.debug("qemu cmdline used:\n{}".format(cmdline)) + except (IndexError, ValueError): + # Try to get network configuration from runqemu output + match = re.match(r'.*Network configuration: (?:ip=)*([0-9.]+)::([0-9.]+):([0-9.]+).*', + out, re.MULTILINE|re.DOTALL) + if match: + self.ip, self.server_ip, self.netmask = match.groups() + # network configuration is required as we couldn't get it + # from the runqemu command line, so qemu doesn't run kernel + # and guest networking is not configured + netconf = True + else: + self.logger.error("Couldn't get ip from qemu command line and runqemu output! " + "Here is the qemu command line used:\n%s\n" + "and output from runqemu:\n%s" % (cmdline, out)) self._dump_host() self.stop() return False - logger.info("qemu cmdline used:\n{}".format(cmdline)) - logger.info("Target IP: %s" % self.ip) - logger.info("Server IP: %s" % self.server_ip) - self.thread = LoggingThread(self.log, threadsock, logger) + self.logger.debug("Target IP: %s" % self.ip) + self.logger.debug("Server IP: %s" % self.server_ip) + + if self.serial_ports >= 2: + self.thread = LoggingThread(self.log, self.threadsock, self.logger) self.thread.start() if not self.thread.connection_established.wait(self.boottime): - logger.error("Didn't receive a console connection from qemu. " + self.logger.error("Didn't receive a console connection from qemu. " "Here is the qemu command line used:\n%s\nand " - "output from runqemu:\n%s" % (cmdline, - self.getOutput(output))) + "output from runqemu:\n%s" % (cmdline, out)) self.stop_thread() return False - logger.info("Output from runqemu:\n%s", self.getOutput(output)) - logger.info("Waiting at most %d seconds for login banner" % self.boottime) - endtime = time.time() + self.boottime - socklist = [self.server_socket] - reachedlogin = False - stopread = False - qemusock = None - bootlog = '' - data = b'' - while time.time() < endtime and not stopread: - sread, swrite, serror = select.select(socklist, [], [], 5) - for sock in sread: - if sock is self.server_socket: - qemusock, addr = self.server_socket.accept() - qemusock.setblocking(0) - socklist.append(qemusock) - socklist.remove(self.server_socket) - logger.info("Connection from %s:%s" % addr) - else: - data = data + sock.recv(1024) - if data: - try: - data = data.decode("utf-8", errors="surrogateescape") - bootlog += data - data = b'' - if re.search(".* login:", bootlog): - self.server_socket = qemusock - stopread = True - reachedlogin = True - logger.info("Reached login banner") - except UnicodeDecodeError: - continue - else: - socklist.remove(sock) - sock.close() - stopread = True - - if not reachedlogin: - logger.info("Target didn't reached login boot in %d seconds" % self.boottime) - lines = "\n".join(bootlog.splitlines()[-25:]) - logger.info("Last 25 lines of text:\n%s" % lines) - logger.info("Check full boot log: %s" % self.logfile) - self._dump_host() - self.stop() - return False - - # If we are not able to login the tests can continue + self.logger.debug("Output from runqemu:\n%s", out) + self.logger.debug("Waiting at most %d seconds for login banner (%s)" % + (self.boottime, time.strftime("%D %H:%M:%S"))) + endtime = time.time() + self.boottime + socklist = [self.server_socket] + reachedlogin = False + stopread = False + qemusock = None + bootlog = b'' + data = b'' + while time.time() < endtime and not stopread: try: - (status, output) = self.run_serial("root\n", raw=True) - if re.search("root@[a-zA-Z0-9\-]+:~#", output): - self.logged = True - logger.info("Logged as root in serial console") + sread, swrite, serror = select.select(socklist, [], [], 5) + except InterruptedError: + continue + for sock in sread: + if sock is self.server_socket: + qemusock, addr = self.server_socket.accept() + qemusock.setblocking(0) + socklist.append(qemusock) + socklist.remove(self.server_socket) + self.logger.debug("Connection from %s:%s" % addr) else: - logger.info("Couldn't login into serial console" - " as root using blank password") - except: - logger.info("Serial console failed while trying to login") - - else: - logger.info("Qemu pid didn't appeared in %s seconds" % self.runqemutime) + data = data + sock.recv(1024) + if data: + bootlog += data + if self.serial_ports < 2: + # this socket has mixed console/kernel data, log it to logfile + self.log(data) + + data = b'' + if self.boot_patterns['search_reached_prompt'] in bootlog: + self.server_socket = qemusock + stopread = True + reachedlogin = True + self.logger.debug("Reached login banner in %s seconds (%s)" % + (time.time() - (endtime - self.boottime), + time.strftime("%D %H:%M:%S"))) + else: + # no need to check if reachedlogin unless we support multiple connections + self.logger.debug("QEMU socket disconnected before login banner reached. (%s)" % + time.strftime("%D %H:%M:%S")) + socklist.remove(sock) + sock.close() + stopread = True + + if not reachedlogin: + if time.time() >= endtime: + self.logger.warning("Target didn't reach login banner in %d seconds (%s)" % + (self.boottime, time.strftime("%D %H:%M:%S"))) + tail = lambda l: "\n".join(l.splitlines()[-25:]) + bootlog = bootlog.decode("utf-8") + # in case bootlog is empty, use tail qemu log store at self.msg + lines = tail(bootlog if bootlog else self.msg) + self.logger.warning("Last 25 lines of text:\n%s" % lines) + self.logger.warning("Check full boot log: %s" % self.logfile) self._dump_host() self.stop() - logger.info("Output from runqemu:\n%s" % self.getOutput(output)) return False - return self.is_alive() + # If we are not able to login the tests can continue + try: + (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120) + if re.search(self.boot_patterns['search_login_succeeded'], output): + self.logged = True + self.logger.debug("Logged as root in serial console") + if netconf: + # configure guest networking + cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask) + output = self.run_serial(cmd, raw=True)[1] + if re.search(r"root@[a-zA-Z0-9\-]+:~#", output): + self.logger.debug("configured ip address %s", self.ip) + else: + self.logger.debug("Couldn't configure guest networking") + else: + self.logger.warning("Couldn't login into serial console" + " as root using blank password") + self.logger.warning("The output:\n%s" % output) + except: + self.logger.warning("Serial console failed while trying to login") + return True def stop(self): - self.stop_thread() - self.stop_qemu_system() if hasattr(self, "origchldhandler"): signal.signal(signal.SIGCHLD, self.origchldhandler) + self.stop_thread() + self.stop_qemu_system() if self.runqemu: if hasattr(self, "monitorpid"): os.kill(self.monitorpid, signal.SIGKILL) - logger.info("Sending SIGTERM to runqemu") + self.logger.debug("Sending SIGTERM to runqemu") try: os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) except OSError as e: @@ -312,14 +536,33 @@ class QemuRunner: while self.runqemu.poll() is None and time.time() < endtime: time.sleep(1) if self.runqemu.poll() is None: - logger.info("Sending SIGKILL to runqemu") + self.logger.debug("Sending SIGKILL to runqemu") os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL) - self.runqemu = None + if not self.runqemu.stdout.closed: + self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout)) + self.runqemu.stdin.close() + self.runqemu.stdout.close() + self.runqemu_exited = True + + if hasattr(self, 'qmp') and self.qmp: + self.qmp.close() + self.qmp = None if hasattr(self, 'server_socket') and self.server_socket: self.server_socket.close() self.server_socket = None + if hasattr(self, 'threadsock') and self.threadsock: + self.threadsock.close() + self.threadsock = None self.qemupid = None self.ip = None + if os.path.exists(self.qemu_pidfile): + try: + os.remove(self.qemu_pidfile) + except FileNotFoundError as e: + # We raced, ignore + pass + if self.monitorpipe: + self.monitorpipe.close() def stop_qemu_system(self): if self.qemupid: @@ -327,15 +570,20 @@ class QemuRunner: # qemu-system behaves well and a SIGTERM is enough os.kill(self.qemupid, signal.SIGTERM) except ProcessLookupError as e: - logger.warn('qemu-system ended unexpectedly') + self.logger.warning('qemu-system ended unexpectedly') def stop_thread(self): if self.thread and self.thread.is_alive(): self.thread.stop() self.thread.join() + def allowexit(self): + self.canexit = True + if self.thread: + self.thread.allowexit() + def restart(self, qemuparams = None): - logger.info("Restarting qemu process") + self.logger.warning("Restarting qemu process") if self.runqemu.poll() is None: self.stop() if self.start(qemuparams): @@ -343,59 +591,33 @@ class QemuRunner: return False def is_alive(self): - if not self.runqemu: + if not self.runqemu or self.runqemu.poll() is not None or self.runqemu_exited: return False - qemu_child = self.find_child(str(self.runqemu.pid)) - if qemu_child: - self.qemupid = qemu_child[0] - if os.path.exists("/proc/" + str(self.qemupid)): - return True + if os.path.isfile(self.qemu_pidfile): + # when handling pidfile, qemu creates the file, stat it, lock it and then write to it + # so it's possible that the file has been created but the content is empty + pidfile_timeout = time.time() + 3 + while time.time() < pidfile_timeout: + with open(self.qemu_pidfile, 'r') as f: + qemu_pid = f.read().strip() + # file created but not yet written contents + if not qemu_pid: + time.sleep(0.5) + continue + else: + if os.path.exists("/proc/" + qemu_pid): + self.qemupid = int(qemu_pid) + return True return False - def find_child(self,parent_pid): - # - # Walk the process tree from the process specified looking for a qemu-system. Return its [pid'cmd] - # - ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,command'], stdout=subprocess.PIPE).communicate()[0] - processes = ps.decode("utf-8").split('\n') - nfields = len(processes[0].split()) - 1 - pids = {} - commands = {} - for row in processes[1:]: - data = row.split(None, nfields) - if len(data) != 3: - continue - if data[1] not in pids: - pids[data[1]] = [] - - pids[data[1]].append(data[0]) - commands[data[0]] = data[2] - - if parent_pid not in pids: - return [] - - parents = [] - newparents = pids[parent_pid] - while newparents: - next = [] - for p in newparents: - if p in pids: - for n in pids[p]: - if n not in parents and n not in next: - next.append(n) - if p not in parents: - parents.append(p) - newparents = next - #print("Children matching %s:" % str(parents)) - for p in parents: - # Need to be careful here since runqemu runs "ldd qemu-system-xxxx" - # Also, old versions of ldd (2.11) run "LD_XXXX qemu-system-xxxx" - basecmd = commands[p].split()[0] - basecmd = os.path.basename(basecmd) - if "qemu-system" in basecmd and "-serial tcp" in commands[p]: - return [int(p),commands[p]] - - def run_serial(self, command, raw=False): + def run_monitor(self, command, args=None, timeout=60): + if hasattr(self, 'qmp') and self.qmp: + if args is not None: + return self.qmp.cmd(command, args) + else: + return self.qmp.cmd(command) + + def run_serial(self, command, raw=False, timeout=60): # We assume target system have echo to get command status if not raw: command = "%s; echo $?\n" % command @@ -403,20 +625,28 @@ class QemuRunner: data = '' status = 0 self.server_socket.sendall(command.encode('utf-8')) - keepreading = True - while keepreading: - sread, _, _ = select.select([self.server_socket],[],[],5) + start = time.time() + end = start + timeout + while True: + now = time.time() + if now >= end: + data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout + break + try: + sread, _, _ = select.select([self.server_socket],[],[], end - now) + except InterruptedError: + continue if sread: answer = self.server_socket.recv(1024) if answer: data += answer.decode('utf-8') # Search the prompt to stop - if re.search("[a-zA-Z0-9]+@[a-zA-Z0-9\-]+:~#", data): - keepreading = False + if re.search(self.boot_patterns['search_cmd_finished'], data): + break else: - raise Exception("No data on serial console socket") - else: - keepreading = False + if self.canexit: + return (1, "") + raise Exception("No data on serial console socket, connection closed?") if data: if raw: @@ -438,7 +668,7 @@ class QemuRunner: def _dump_host(self): self.host_dumper.create_dir("qemu") - logger.warn("Qemu ended unexpectedly, dump data from host" + self.logger.warning("Qemu ended unexpectedly, dump data from host" " is in %s" % self.host_dumper.dump_dir) self.host_dumper.dump_host() @@ -454,6 +684,7 @@ class LoggingThread(threading.Thread): self.logger = logger self.readsock = None self.running = False + self.canexit = False self.errorevents = select.POLLERR | select.POLLHUP | select.POLLNVAL self.readevents = select.POLLIN | select.POLLPRI @@ -467,17 +698,17 @@ class LoggingThread(threading.Thread): self.teardown() def run(self): - self.logger.info("Starting logging thread") + self.logger.debug("Starting logging thread") self.readpipe, self.writepipe = os.pipe() threading.Thread.run(self) def stop(self): - self.logger.info("Stopping logging thread") + self.logger.debug("Stopping logging thread") if self.running: os.write(self.writepipe, bytes("stop", "utf-8")) def teardown(self): - self.logger.info("Tearing down logging thread") + self.logger.debug("Tearing down logging thread") self.close_socket(self.serversock) if self.readsock is not None: @@ -487,6 +718,9 @@ class LoggingThread(threading.Thread): self.close_ignore_error(self.writepipe) self.running = False + def allowexit(self): + self.canexit = True + def eventloop(self): poll = select.poll() event_read_mask = self.errorevents | self.readevents @@ -495,7 +729,7 @@ class LoggingThread(threading.Thread): breakout = False self.running = True - self.logger.info("Starting thread event loop") + self.logger.debug("Starting thread event loop") while not breakout: events = poll.poll() for event in events: @@ -505,19 +739,19 @@ class LoggingThread(threading.Thread): # Event to stop the thread if self.readpipe == event[0]: - self.logger.info("Stop event received") + self.logger.debug("Stop event received") breakout = True break # A connection request was received elif self.serversock.fileno() == event[0]: - self.logger.info("Connection request received") + self.logger.debug("Connection request received") self.readsock, _ = self.serversock.accept() self.readsock.setblocking(0) poll.unregister(self.serversock.fileno()) poll.register(self.readsock.fileno(), event_read_mask) - self.logger.info("Setting connection established event") + self.logger.debug("Setting connection established event") self.connection_established.set() # Actual data to be logged @@ -532,7 +766,7 @@ class LoggingThread(threading.Thread): data = self.readsock.recv(count) except socket.error as e: if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK: - return '' + return b'' else: raise @@ -543,7 +777,9 @@ class LoggingThread(threading.Thread): # happened. But for this code it counts as an # error since the connection shouldn't go away # until qemu exits. - raise Exception("Console connection closed unexpectedly") + if not self.canexit: + raise Exception("Console connection closed unexpectedly") + return b'' return data diff --git a/meta/lib/oeqa/utils/qemutinyrunner.py b/meta/lib/oeqa/utils/qemutinyrunner.py index ec52473834..20009401ca 100644 --- a/meta/lib/oeqa/utils/qemutinyrunner.py +++ b/meta/lib/oeqa/utils/qemutinyrunner.py @@ -1,6 +1,8 @@ +# # Copyright (C) 2015 Intel Corporation # -# Released under the MIT license (see COPYING.MIT) +# SPDX-License-Identifier: MIT +# # This module provides a class for starting qemu images of poky tiny. # It's used by testimage.bbclass. @@ -17,7 +19,7 @@ from .qemurunner import QemuRunner class QemuTinyRunner(QemuRunner): - def __init__(self, machine, rootfs, display, tmpdir, deploy_dir_image, logfile, kernel, boottime): + def __init__(self, machine, rootfs, display, tmpdir, deploy_dir_image, logfile, kernel, boottime, logger, tmpfsdir=None): # Popen object for runqemu self.runqemu = None @@ -35,11 +37,13 @@ class QemuTinyRunner(QemuRunner): self.deploy_dir_image = deploy_dir_image self.logfile = logfile self.boottime = boottime + self.tmpfsdir = tmpfsdir self.runqemutime = 60 self.socketfile = "console.sock" self.server_socket = None self.kernel = kernel + self.logger = logger def create_socket(self): @@ -60,7 +64,7 @@ class QemuTinyRunner(QemuRunner): with open(self.logfile, "a") as f: f.write("%s" % msg) - def start(self, qemuparams = None, ssh=True, extra_bootparams=None, runqemuparams=''): + def start(self, qemuparams = None, ssh=True, extra_bootparams=None, runqemuparams='', discard_writes=True): if self.display: os.environ["DISPLAY"] = self.display @@ -80,6 +84,9 @@ class QemuTinyRunner(QemuRunner): return False else: os.environ["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image + if self.tmpfsdir: + env["RUNQEMU_TMPFS_DIR"] = self.tmpfsdir + # Set this flag so that Qemu doesn't do any grabs as SDL grabs interact # badly with screensavers. @@ -107,14 +114,17 @@ class QemuTinyRunner(QemuRunner): return self.is_alive() - def run_serial(self, command): + def run_serial(self, command, timeout=60): self.server_socket.sendall(command+'\n') data = '' status = 0 stopread = False - endtime = time.time()+5 + endtime = time.time()+timeout while time.time()<endtime and not stopread: - sread, _, _ = select.select([self.server_socket],[],[],5) + try: + sread, _, _ = select.select([self.server_socket],[],[],1) + except InterruptedError: + continue for sock in sread: answer = sock.recv(1024) if answer: @@ -124,13 +134,15 @@ class QemuTinyRunner(QemuRunner): stopread = True if not data: status = 1 + if not stopread: + data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout return (status, str(data)) def find_child(self,parent_pid): # # Walk the process tree from the process specified looking for a qemu-system. Return its [pid'cmd] # - ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,command'], stdout=subprocess.PIPE).communicate()[0] + ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,pri,ni,command'], stdout=subprocess.PIPE).communicate()[0] processes = ps.decode("utf-8").split('\n') nfields = len(processes[0].split()) - 1 pids = {} diff --git a/meta/lib/oeqa/utils/sshcontrol.py b/meta/lib/oeqa/utils/sshcontrol.py index 05d6502550..36c2ecb3db 100644 --- a/meta/lib/oeqa/utils/sshcontrol.py +++ b/meta/lib/oeqa/utils/sshcontrol.py @@ -1,7 +1,8 @@ -# -*- coding: utf-8 -*- +# # Copyright (C) 2013 Intel Corporation # -# Released under the MIT license (see COPYING.MIT) +# SPDX-License-Identifier: MIT +# # Provides a class for setting up ssh connections, # running commands and copying files to/from a target. @@ -22,7 +23,7 @@ class SSHProcess(object): "stdin": None, "shell": False, "bufsize": -1, - "preexec_fn": os.setsid, + "start_new_session": True, } self.options = dict(self.defaultopts) self.options.update(options) @@ -150,12 +151,9 @@ class SSHControl(object): def copy_to(self, localpath, remotepath): if os.path.islink(localpath): - link = os.readlink(localpath) - dst_dir, dst_base = os.path.split(remotepath) - return self.run("cd %s; ln -s %s %s" % (dst_dir, link, dst_base)) - else: - command = self.scp + [localpath, '%s@%s:%s' % (self.user, self.ip, remotepath)] - return self._internal_run(command, ignore_status=False) + localpath = os.path.dirname(localpath) + "/" + os.readlink(localpath) + command = self.scp + [localpath, '%s@%s:%s' % (self.user, self.ip, remotepath)] + return self._internal_run(command, ignore_status=False) def copy_from(self, remotepath, localpath): command = self.scp + ['%s@%s:%s' % (self.user, self.ip, remotepath), localpath] diff --git a/meta/lib/oeqa/utils/subprocesstweak.py b/meta/lib/oeqa/utils/subprocesstweak.py index 1f7d11b55c..b47975a4bc 100644 --- a/meta/lib/oeqa/utils/subprocesstweak.py +++ b/meta/lib/oeqa/utils/subprocesstweak.py @@ -1,3 +1,6 @@ +# +# SPDX-License-Identifier: MIT +# import subprocess class OETestCalledProcessError(subprocess.CalledProcessError): diff --git a/meta/lib/oeqa/utils/targetbuild.py b/meta/lib/oeqa/utils/targetbuild.py index 6f237b56f3..09738add1d 100644 --- a/meta/lib/oeqa/utils/targetbuild.py +++ b/meta/lib/oeqa/utils/targetbuild.py @@ -1,6 +1,8 @@ +# # Copyright (C) 2013 Intel Corporation # -# Released under the MIT license (see COPYING.MIT) +# SPDX-License-Identifier: MIT +# # Provides a class for automating build tests for projects @@ -8,15 +10,22 @@ import os import re import bb.utils import subprocess +import tempfile from abc import ABCMeta, abstractmethod class BuildProject(metaclass=ABCMeta): - def __init__(self, d, uri, foldername=None, tmpdir="/tmp/"): + def __init__(self, d, uri, foldername=None, tmpdir=None): self.d = d self.uri = uri self.archive = os.path.basename(uri) - self.localarchive = os.path.join(tmpdir,self.archive) + self.tempdirobj = None + if not tmpdir: + tmpdir = self.d.getVar('WORKDIR') + if not tmpdir: + self.tempdirobj = tempfile.TemporaryDirectory(prefix='buildproject-') + tmpdir = self.tempdirobj.name + self.localarchive = os.path.join(tmpdir, self.archive) if foldername: self.fname = foldername else: @@ -24,7 +33,6 @@ class BuildProject(metaclass=ABCMeta): # Download self.archive to self.localarchive def _download_archive(self): - dl_dir = self.d.getVar("DL_DIR") if dl_dir and os.path.exists(os.path.join(dl_dir, self.archive)): bb.utils.copyfile(os.path.join(dl_dir, self.archive), self.localarchive) @@ -64,16 +72,17 @@ class BuildProject(metaclass=ABCMeta): return self._run('cd %s; make install %s' % (self.targetdir, install_args)) def clean(self): + if self.tempdirobj: + self.tempdirobj.cleanup() self._run('rm -rf %s' % self.targetdir) - subprocess.call('rm -f %s' % self.localarchive, shell=True) - pass + subprocess.check_call('rm -f %s' % self.localarchive, shell=True) class TargetBuildProject(BuildProject): def __init__(self, target, d, uri, foldername=None): self.target = target self.targetdir = "~/" - BuildProject.__init__(self, d, uri, foldername, tmpdir="/tmp") + BuildProject.__init__(self, d, uri, foldername) def download_archive(self): @@ -132,4 +141,4 @@ class SDKBuildProject(BuildProject): def _run(self, cmd): self.log("Running . %s; " % self.sdkenv + cmd) - return subprocess.call(". %s; " % self.sdkenv + cmd, shell=True) + return subprocess.check_call(". %s; " % self.sdkenv + cmd, shell=True) diff --git a/meta/lib/oeqa/utils/testexport.py b/meta/lib/oeqa/utils/testexport.py index be2a2110fc..e89d130a9c 100644 --- a/meta/lib/oeqa/utils/testexport.py +++ b/meta/lib/oeqa/utils/testexport.py @@ -1,6 +1,8 @@ +# # Copyright (C) 2015 Intel Corporation # -# Released under the MIT license (see COPYING.MIT) +# SPDX-License-Identifier: MIT +# # Provides functions to help with exporting binaries obtained from built targets |