testimage: performance improvements

Refactored processing of QEMU logs.
The original code read QEMU logs every 30 seconds, which
resulted in each test taking at least 30 seconds to finish.
In reality, most tests take only a few seconds.
Although the tests run in parallel, on systems with only a few
CPUs this can make a very noticable difference.

Signed-off-by: Juro Bystricky <juro.bystricky@intel.com>
This commit is contained in:
Juro Bystricky
2017-02-05 20:14:29 -08:00
parent c42423e291
commit 32e3cf773e
4 changed files with 123 additions and 101 deletions

View File

@@ -1,66 +0,0 @@
# Copyright (C) 2013-2016 Intel Corporation
#
# Released under the MIT license (see COPYING.MIT)
# This module is used by testimage.bbclass for setting up and controlling a target machine.
import os
import shutil
import bb
import logging
from oeqa.targetcontrol import QemuTarget
from oeqa.utils.dump import TargetDumper
from oeqa.utils.qemuzephyrrunner import QemuZephyrRunner
class QemuTargetZephyr(QemuTarget):
def __init__(self, d):
super(QemuTarget, self).__init__(d)
self.qemulog = os.path.join(self.testdir, "qemu_boot_log.%s" % self.datetime)
dump_target_cmds = d.getVar("testimage_dump_target", True)
dump_host_cmds = d.getVar("testimage_dump_host", True)
dump_dir = d.getVar("TESTIMAGE_DUMP_DIR", True)
self.kernel = os.path.join(d.getVar("DEPLOY_DIR_IMAGE", True), d.getVar("ZEPHYR_IMAGENAME", True))
self.rootfs = ""
# Log QemuRunner log output to a file
import oe.path
from oeqa.utils.qemuzephyrrunner import QemuZephyrRunner
bb.utils.mkdirhier(self.testdir)
self.qemurunnerlog = os.path.join(self.testdir, 'qemurunner_log.%s' % self.datetime)
logger = logging.getLogger('BitBake.QemuRunner')
loggerhandler = logging.FileHandler(self.qemurunnerlog)
loggerhandler.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))
logger.addHandler(loggerhandler)
oe.path.symlink(os.path.basename(self.qemurunnerlog), os.path.join(self.testdir, 'qemurunner_log'), force=True)
self.runner = QemuZephyrRunner(machine=d.getVar("MACHINE", True),
rootfs=self.rootfs,
tmpdir = d.getVar("TMPDIR", True),
deploy_dir_image = d.getVar("DEPLOY_DIR_IMAGE", True),
display = d.getVar("BB_ORIGENV", False).getVar("DISPLAY", True),
logfile = self.qemulog,
kernel = self.kernel,
boottime = int(d.getVar("TEST_QEMUBOOT_TIMEOUT", True)))
self.target_dumper = TargetDumper(dump_target_cmds, dump_dir, self.runner)
def deploy(self):
try:
bb.utils.mkdirhier(self.testdir)
if self.rootfs:
shutil.copyfile(self.origrootfs, self.rootfs)
except Exception as e:
bb.fatal("Error copying rootfs: %s" % e)
qemuloglink = os.path.join(self.testdir, "qemu_boot_log")
if os.path.islink(qemuloglink):
os.unlink(qemuloglink)
os.symlink(self.qemulog, qemuloglink)
bb.note("Qemu log file: %s" % self.qemulog)
super(QemuTarget, self).deploy()
def wait_for_serial(self, func_timeout, data_timeout):
return self.runner.wait_for_serial(func_timeout, data_timeout)

View File

@@ -0,0 +1,59 @@
# Copyright (C) 2016-2017 Intel Corporation
# Released under the MIT license (see COPYING.MIT)
import os
import sys
import signal
import logging
from oeqa.core.target.__init__ import OETarget
from oeqa.utils.qemuzephyrrunner import QemuZephyrRunner
supported_fstypes = ['elf']
class QemuTargetZephyr(OETarget):
def __init__(self, logger, ip, server_ip, timeout=300, user='root',
port=None, machine='', rootfs='', kernel='', kvm=False,
dump_dir='', dump_host_cmds='', display='', bootlog='',
tmpdir='', dir_image='', boottime=60):
super(QemuTargetZephyr, self).__init__(logger, ip, server_ip, timeout,
user, port)
self.ip = ip
self.server_ip = server_ip
self.machine = machine
self.rootfs = rootfs
self.qemulog = bootlog
self.kernel = kernel
self.kvm = kvm
# Log QemuRunner log output to a file
import oe.path
from oeqa.utils.qemuzephyrrunner import QemuZephyrRunner
self.qemurunnerlog = bootlog
logger = logging.getLogger('BitBake.QemuRunner')
loggerhandler = logging.FileHandler(self.qemurunnerlog)
loggerhandler.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))
logger.addHandler(loggerhandler)
self.runner = QemuZephyrRunner(machine=machine, rootfs=rootfs, tmpdir=tmpdir,
deploy_dir_image=dir_image, display=display,
logfile=self.qemulog, boottime=boottime,
use_kvm=kvm, dump_dir=dump_dir,
dump_host_cmds=dump_host_cmds)
def start(self, params=None, extra_bootparams=None):
if self.runner.start(params, extra_bootparams=extra_bootparams):
self.ip = self.runner.ip
self.server_ip = self.runner.server_ip
else:
self.stop()
raise RuntimeError("FAILED to start qemu - check the task log and the boot log")
def stop(self):
self.runner.stop()
def serial_readline(self):
return self.runner.serial_readline()

View File

@@ -5,19 +5,25 @@ class ZephyrTest(oeRuntimeTest):
def test_boot_zephyr(self):
success = False
logfile = self.target.wait_for_serial(180, 30)
logfile = self.target.qemurunnerlog
while True:
line = self.target.serial_readline().decode("utf-8")
with open(logfile) as f:
for line in f:
# All good
if "PROJECT EXECUTION SUCCESSFUL" in line:
success = True
break
# Most likely cause for faults is incorrectly compiled code
if "***** USAGE FAULT *****" in line:
success = False
self.assertTrue(success, msg='***** USAGE FAULT *****" in file:///%s' % logfile)
break
# All good
if "PROJECT EXECUTION SUCCESSFUL" in line:
success = True
break
if "PROJECT EXECUTION FAILED" in line:
success = False
self.assertTrue(success, msg='PROJECT EXECUTION FAILED in file:///%s' % logfile)
break
# Most likely cause for faults is incorrectly compiled code
if "***** USAGE FAULT *****" in line:
success = False
self.assertTrue(success, msg='***** USAGE FAULT *****" in file:///%s' % logfile)
break
# test program finished, complain if no success message
self.assertTrue(success, msg='"PROJECT EXECUTION SUCCESSFUL" not in file:///%s' % logfile)

View File

@@ -1,8 +1,8 @@
# Copyright (C) 2015-2016 Intel Corporation
# Copyright (C) 2015-2017 Intel Corporation
#
# Released under the MIT license (see COPYING.MIT)
# This module provides a class for starting qemu images of poky tiny.
# This module provides a class for starting qemu images.
# It's used by testimage.bbclass.
import subprocess
@@ -13,21 +13,31 @@ import socket
import select
import bb
import tempfile
import sys
from oeqa.utils.qemurunner import QemuRunner
class QemuZephyrRunner(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, boottime, dump_dir, dump_host_cmds, use_kvm):
QemuRunner.__init__(self, machine, rootfs, display, tmpdir,
deploy_dir_image, logfile, boottime, None,
None, True)
None, use_kvm)
# Popen object for runqemu
self.socketfile = tempfile.NamedTemporaryFile()
self.runqemu = None
self.socketname = self.socketfile.name
self.server_socket = None
self.kernel = kernel
self.kernel = rootfs
self.deploy_dir_image = deploy_dir_image
self.logfile = logfile
self.use_kvm = use_kvm
self.buffers = b''
self._rbufsize = 4096
# 5 minutes timeout...
self.endtime = time.time() + 60*5
def create_socket(self):
bb.note("waiting at most %s seconds for qemu pid" % self.runqemutime)
@@ -49,10 +59,10 @@ class QemuZephyrRunner(QemuRunner):
return False
return True
def start(self, qemuparams = None, get_ip = True, extra_bootparams = None):
def start(self, params=None, extra_bootparams=None):
if not os.path.exists(self.tmpdir):
bb.error("Invalid TMPDIR path %s" % self.tmpdir)
#logger.error("Invalid TMPDIR path %s" % self.tmpdir)
return False
else:
os.environ["OE_TMPDIR"] = self.tmpdir
@@ -63,7 +73,7 @@ class QemuZephyrRunner(QemuRunner):
os.environ["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image
if not os.path.exists(self.kernel):
bb.error("Invalid kernel path: %s" % self.deploy_dir_image)
bb.error("Invalid kernel path: %s" % self.kernel)
return False
self.qemuparams = '-nographic -serial unix:%s,server' % (self.socketname)
@@ -117,20 +127,33 @@ class QemuZephyrRunner(QemuRunner):
bb.note("qemu started, pid is %s" % self.runqemu.pid)
return self.create_socket()
def wait_for_serial(self, func_timeout, data_timeout):
stopread = False
check_endtime = False
self.server_socket.setblocking(0)
endtime = time.time() + func_timeout
def _readline(self):
nl = self.buffers.find(b'\n')
if nl >= 0:
nl += 1
line = self.buffers[:nl]
newbuf = self.buffers[nl:]
self.buffers = newbuf
return line
return None
def serial_readline(self):
line = self._readline()
if line is None:
while True:
if time.time() >= self.endtime:
bb.warn("Timeout!")
raise Exception("Timeout")
data = self.server_socket.recv(self._rbufsize)
if data is None:
raise Exception("No data on read ready socket")
self.buffers = self.buffers + data
line = self._readline()
if line is not None:
break
self.log(line)
return line
while time.time() < endtime:
sread, _, _ = select.select([self.server_socket],[],[],data_timeout)
if not sread:
break
answer = self.server_socket.recv(1024)
if answer:
self.log(answer)
else:
break
return self.logfile