diff options
Diffstat (limited to 'import-layers/yocto-poky/meta/lib/oeqa/utils')
10 files changed, 321 insertions, 268 deletions
diff --git a/import-layers/yocto-poky/meta/lib/oeqa/utils/__init__.py b/import-layers/yocto-poky/meta/lib/oeqa/utils/__init__.py index 485de031a..d38a32301 100644 --- a/import-layers/yocto-poky/meta/lib/oeqa/utils/__init__.py +++ b/import-layers/yocto-poky/meta/lib/oeqa/utils/__init__.py @@ -2,7 +2,6 @@ from pkgutil import extend_path __path__ = extend_path(__path__, __name__) - # Borrowed from CalledProcessError class CommandError(Exception): @@ -66,3 +65,39 @@ def make_logger_bitbake_compatible(logger): 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/import-layers/yocto-poky/meta/lib/oeqa/utils/buildproject.py b/import-layers/yocto-poky/meta/lib/oeqa/utils/buildproject.py index 487f08be4..721f35d99 100644 --- a/import-layers/yocto-poky/meta/lib/oeqa/utils/buildproject.py +++ b/import-layers/yocto-poky/meta/lib/oeqa/utils/buildproject.py @@ -52,4 +52,4 @@ class BuildProject(metaclass=ABCMeta): def clean(self): 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/import-layers/yocto-poky/meta/lib/oeqa/utils/commands.py b/import-layers/yocto-poky/meta/lib/oeqa/utils/commands.py index 57286fcb1..0bb90028d 100644 --- a/import-layers/yocto-poky/meta/lib/oeqa/utils/commands.py +++ b/import-layers/yocto-poky/meta/lib/oeqa/utils/commands.py @@ -13,6 +13,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 +26,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 +49,103 @@ 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: + threading.Thread(target=writeThread, daemon=True).start() + 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.isAlive(): + 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.isAlive(): 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.log.debug("Command '%s' returned %d as exit code." % (self.cmd, self.status)) # logging the complete output is insane @@ -98,7 +161,7 @@ class Result(object): def runCmd(command, ignore_status=False, timeout=None, assert_error=True, - native_sysroot=None, limit_exc_output=0, **options): + native_sysroot=None, limit_exc_output=0, output_log=None, **options): result = Result() if native_sysroot: @@ -108,7 +171,7 @@ def runCmd(command, ignore_status=False, timeout=None, assert_error=True, 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() result.command = command @@ -132,7 +195,7 @@ def runCmd(command, ignore_status=False, timeout=None, assert_error=True, 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') @@ -147,7 +210,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) @@ -233,6 +296,12 @@ def runqemu(pn, ssh=True, runqemuparams='', image_fstype=None, launch_cmd=None, 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: @@ -250,31 +319,15 @@ def runqemu(pn, ssh=True, runqemuparams='', image_fstype=None, launch_cmd=None, 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: @@ -289,6 +342,7 @@ def runqemu(pn, ssh=True, runqemuparams='', image_fstype=None, launch_cmd=None, qemu.stop() except: pass + targetlogger.removeHandler(handler) def updateEnv(env_file): """ diff --git a/import-layers/yocto-poky/meta/lib/oeqa/utils/git.py b/import-layers/yocto-poky/meta/lib/oeqa/utils/git.py index e0cb3f0db..757e3f0cb 100644 --- a/import-layers/yocto-poky/meta/lib/oeqa/utils/git.py +++ b/import-layers/yocto-poky/meta/lib/oeqa/utils/git.py @@ -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/import-layers/yocto-poky/meta/lib/oeqa/utils/logparser.py b/import-layers/yocto-poky/meta/lib/oeqa/utils/logparser.py index b377dcd27..0670627c3 100644 --- a/import-layers/yocto-poky/meta/lib/oeqa/utils/logparser.py +++ b/import-layers/yocto-poky/meta/lib/oeqa/utils/logparser.py @@ -9,7 +9,7 @@ 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): + def __init__(self, test_0_pass_regex, test_0_fail_regex, test_0_skip_regex, section_0_begin_regex=None, section_0_end_regex=None, **kwargs): # Initialize the arguments dictionary if kwargs: self.args = kwargs @@ -19,12 +19,13 @@ class Lparser(object): # 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 + self.args['test_0_skip_regex'] = test_0_skip_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.test_possible_status = ['pass', 'fail', 'error', 'skip'] self.section_possible_status = ['begin', 'end'] self.initialized = False @@ -108,7 +109,7 @@ class Result(object): prefix = '' for x in test_status: prefix +=x+'.' - if (section != ''): + if section: prefix += section section_file = os.path.join(target_dir, prefix) # purge the file contents if it exists diff --git a/import-layers/yocto-poky/meta/lib/oeqa/utils/metadata.py b/import-layers/yocto-poky/meta/lib/oeqa/utils/metadata.py index cb81155e5..65bbdc61f 100644 --- a/import-layers/yocto-poky/meta/lib/oeqa/utils/metadata.py +++ b/import-layers/yocto-poky/meta/lib/oeqa/utils/metadata.py @@ -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__)) diff --git a/import-layers/yocto-poky/meta/lib/oeqa/utils/qemurunner.py b/import-layers/yocto-poky/meta/lib/oeqa/utils/qemurunner.py index ba44b96f5..0631d4321 100644 --- a/import-layers/yocto-poky/meta/lib/oeqa/utils/qemurunner.py +++ b/import-layers/yocto-poky/meta/lib/oeqa/utils/qemurunner.py @@ -17,11 +17,8 @@ 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()) +from oeqa.utils.dump import HostDumper # Get Unicode non printable control chars control_range = list(range(0,32))+list(range(127,160)) @@ -31,7 +28,7 @@ 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): # Popen object for runqemu self.runqemu = None @@ -54,10 +51,14 @@ class QemuRunner: self.logged = False self.thread = None self.use_kvm = use_kvm + self.msg = '' - self.runqemutime = 60 + self.runqemutime = 120 + self.qemu_pidfile = 'pidfile_'+str(os.getpid()) self.host_dumper = HostDumper(dump_host_cmds, dump_dir) + self.logger = logger + def create_socket(self): try: sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM) @@ -65,7 +66,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: @@ -78,6 +79,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) @@ -91,58 +93,63 @@ class QemuRunner: 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.debug('runqemu exited with code %d' % self.runqemu.returncode) + self.logger.debug("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='', 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 not launch_cmd: launch_cmd = 'runqemu %s %s ' % ('snapshot' if discard_writes else '', runqemuparams) if self.use_kvm: - logger.info('Using kvm for runqemu') + self.logger.debug('Using kvm for runqemu') launch_cmd += ' kvm' else: - logger.info('Not using kvm for runqemu') + self.logger.debug('Not using kvm for runqemu') if not self.display: launch_cmd += ' nographic' launch_cmd += ' %s %s' % (self.machine, self.rootfs) - return self.launch(launch_cmd, qemuparams=qemuparams, get_ip=get_ip, extra_bootparams=extra_bootparams) + 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): + def launch(self, launch_cmd, get_ip = True, qemuparams = None, extra_bootparams = None, env = None): try: 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' if extra_bootparams: bootparams = bootparams + ' ' + extra_bootparams - self.qemuparams = 'bootparams="{0}" qemuparams="-serial tcp:127.0.0.1:{1}"'.format(bootparams, threadport) + # 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="-serial tcp:127.0.0.1:{1} -pidfile {2}"'.format(bootparams, threadport, self.qemu_pidfile) if qemuparams: self.qemuparams = self.qemuparams[:-1] + " " + qemuparams + " " + '\"' @@ -151,13 +158,13 @@ class QemuRunner: self.origchldhandler = signal.getsignal(signal.SIGCHLD) signal.signal(signal.SIGCHLD, self.handleSIGCHLD) - 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) output = self.runqemu.stdout # @@ -186,143 +193,149 @@ class QemuRunner: os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) sys.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" % self.runqemutime) endtime = time.time() + self.runqemutime while not self.is_alive() and time.time() < endtime: if self.runqemu.poll(): if self.runqemu.returncode: # No point waiting any longer - logger.info('runqemu exited with code %d' % self.runqemu.returncode) + self.logger.debug('runqemu exited with code %d' % self.runqemu.returncode) self._dump_host() self.stop() - logger.info("Output from runqemu:\n%s" % self.getOutput(output)) + self.logger.debug("Output from runqemu:\n%s" % self.getOutput(output)) return False - time.sleep(1) + time.sleep(0.5) + + if not self.is_alive(): + self.logger.error("Qemu pid didn't appear in %s seconds" % self.runqemutime) + # Dump all processes to help us to figure out what is going on... + ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,command '], stdout=subprocess.PIPE).communicate()[0] + processes = ps.decode("utf-8") + self.logger.debug("Running processes:\n%s" % processes) + self._dump_host() + self.stop() + op = self.getOutput(output) + if op: + self.logger.error("Output from runqemu:\n%s" % op) + else: + self.logger.error("No output from runqemu.\n") + return False + # We are alive: qemu is running out = self.getOutput(output) netconf = False # network configuration is not required by default - 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) - try: - ips = re.findall("((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1]) - self.ip = ips[0] - self.server_ip = ips[1] - logger.info("qemu cmdline used:\n{}".format(cmdline)) - except (IndexError, ValueError): - # Try to get network configuration from runqemu output - match = re.match('.*Network configuration: ([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: - 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("Target IP: %s" % self.ip) - logger.info("Server IP: %s" % self.server_ip) - - self.thread = LoggingThread(self.log, threadsock, logger) - self.thread.start() - if not self.thread.connection_established.wait(self.boottime): - 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, out)) - self.stop_thread() - return False - - logger.info("Output from runqemu:\n%s", out) - 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: - try: - 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) - 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 + self.logger.debug("qemu started in %s seconds - qemu procces pid is %s" % (time.time() - (endtime - self.runqemutime), 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) + try: + ips = re.findall("((?:[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('.*Network configuration: ([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 - 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 + self.logger.debug("Target IP: %s" % self.ip) + self.logger.debug("Server IP: %s" % self.server_ip) - # If we are not able to login the tests can continue + self.thread = LoggingThread(self.log, threadsock, self.logger) + self.thread.start() + if not self.thread.connection_established.wait(self.boottime): + 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, out)) + self.stop_thread() + return False + + self.logger.debug("Output from runqemu:\n%s", out) + self.logger.debug("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 = 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") - 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("root@[a-zA-Z0-9\-]+:~#", output): - logger.info("configured ip address %s", self.ip) - else: - logger.info("Couldn't configure guest networking") + 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 + data = b'' + if b' login:' in bootlog: + self.server_socket = qemusock + stopread = True + reachedlogin = True + self.logger.debug("Reached login banner") + else: + socklist.remove(sock) + sock.close() + stopread = True + + + if not reachedlogin: + self.logger.debug("Target didn't reached login boot in %d seconds" % self.boottime) + tail = lambda l: "\n".join(l.splitlines()[-25:]) + # in case bootlog is empty, use tail qemu log store at self.msg + lines = tail(bootlog if bootlog else self.msg) + self.logger.debug("Last 25 lines of text:\n%s" % lines) + self.logger.debug("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("root\n", raw=True) + if re.search("root@[a-zA-Z0-9\-]+:~#", 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("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.debug("Couldn't login into serial console" + " as root using blank password") + except: + self.logger.debug("Serial console failed while trying to login") + return True def stop(self): self.stop_thread() @@ -332,7 +345,7 @@ class QemuRunner: 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: @@ -342,7 +355,7 @@ 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 hasattr(self, 'server_socket') and self.server_socket: @@ -350,6 +363,8 @@ class QemuRunner: self.server_socket = None self.qemupid = None self.ip = None + if os.path.exists(self.qemu_pidfile): + os.remove(self.qemu_pidfile) def stop_qemu_system(self): if self.qemupid: @@ -357,7 +372,7 @@ 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.warn('qemu-system ended unexpectedly') def stop_thread(self): if self.thread and self.thread.is_alive(): @@ -365,7 +380,7 @@ class QemuRunner: self.thread.join() def restart(self, qemuparams = None): - logger.info("Restarting qemu process") + self.logger.debug("Restarting qemu process") if self.runqemu.poll() is None: self.stop() if self.start(qemuparams): @@ -375,56 +390,16 @@ class QemuRunner: def is_alive(self): if not self.runqemu: 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)): + if os.path.isfile(self.qemu_pidfile): + f = open(self.qemu_pidfile, 'r') + qemu_pid = f.read() + f.close() + qemupid = int(qemu_pid) + if os.path.exists("/proc/" + str(qemupid)): + self.qemupid = qemupid 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, timeout=5): # We assume target system have echo to get command status if not raw: @@ -474,7 +449,7 @@ class QemuRunner: def _dump_host(self): self.host_dumper.create_dir("qemu") - logger.warn("Qemu ended unexpectedly, dump data from host" + self.logger.warn("Qemu ended unexpectedly, dump data from host" " is in %s" % self.host_dumper.dump_dir) self.host_dumper.dump_host() @@ -503,17 +478,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: @@ -531,7 +506,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: @@ -541,19 +516,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 diff --git a/import-layers/yocto-poky/meta/lib/oeqa/utils/qemutinyrunner.py b/import-layers/yocto-poky/meta/lib/oeqa/utils/qemutinyrunner.py index 1bf59007f..63b5d1648 100644 --- a/import-layers/yocto-poky/meta/lib/oeqa/utils/qemutinyrunner.py +++ b/import-layers/yocto-poky/meta/lib/oeqa/utils/qemutinyrunner.py @@ -17,7 +17,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): # Popen object for runqemu self.runqemu = None @@ -40,6 +40,7 @@ class QemuTinyRunner(QemuRunner): self.socketfile = "console.sock" self.server_socket = None self.kernel = kernel + self.logger = logger def create_socket(self): diff --git a/import-layers/yocto-poky/meta/lib/oeqa/utils/sshcontrol.py b/import-layers/yocto-poky/meta/lib/oeqa/utils/sshcontrol.py index 05d650255..d292893c0 100644 --- a/import-layers/yocto-poky/meta/lib/oeqa/utils/sshcontrol.py +++ b/import-layers/yocto-poky/meta/lib/oeqa/utils/sshcontrol.py @@ -150,12 +150,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/import-layers/yocto-poky/meta/lib/oeqa/utils/targetbuild.py b/import-layers/yocto-poky/meta/lib/oeqa/utils/targetbuild.py index 9249fa263..1202d579f 100644 --- a/import-layers/yocto-poky/meta/lib/oeqa/utils/targetbuild.py +++ b/import-layers/yocto-poky/meta/lib/oeqa/utils/targetbuild.py @@ -69,7 +69,7 @@ class BuildProject(metaclass=ABCMeta): def clean(self): 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) pass class TargetBuildProject(BuildProject): @@ -136,4 +136,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) |
