[PATCH 0/5] runqemu/testimage logging fixes

[PATCH 0/5] runqemu/testimage logging fixes

[Paul Eggleton]

A fix for https://bugzilla.yoctoproject.org/show_bug.cgi?id=13681 along
with some fixes for other minor related issues with the logging when
testimage runs QEMU.

(The "host dump" functionality may be of questionable usefulness, but
at least it now works again.)


The following changes since commit d821415ab09248a894d58f6e5a5749e822d30939:

  wayland: Add PACKAGECONFIG for dtd-validation (2019-12-09 10:21:24 +0000)

are available in the Git repository at:

  git://git.openembedded.org/openembedded-core-contrib paule/runqemu-fixes-oe
  http://cgit.openembedded.org/openembedded-core-contrib/log/?h=paule/runqemu-fixes-oe

Paul Eggleton (5):
  oeqa: qemu: ensure that host dump commands can be run properly
  oeqa: qemu: fix width of top output in host dump
  oeqa: qemu: ensure we print runqemu output in the event of failure
  runqemu: log parameters correctly within testimage
  runqemu: handle tap device creation failure properly

 meta/lib/oeqa/utils/dump.py       |  5 ++++-
 meta/lib/oeqa/utils/qemurunner.py |  4 ++--
 scripts/runqemu                   | 33 ++++++++++++++++++-------------
 3 files changed, 25 insertions(+), 17 deletions(-)

-- 
2.20.1

[PATCH 1/5] oeqa: qemu: ensure that host dump commands can be run properly

[Paul Eggleton]

If runqemu fails, there is some logic to run a set of commands to dump
various bits of information that might help debug the issue
(particularly in a busy situation such as on the autobuilder). However,
when we try to run these we are inside the normal build environment
which restricts commands to be run on the host to those specified in
HOSTTOOLS. Since this isn't a place where host contamination is going to
be a problem, override PATH to a reasonable default so that we run the
actual host tools directly to avoid the issue. (Logically we would want
to use the original PATH value here, but it is not easily accessible.)

Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.com>
---
 meta/lib/oeqa/utils/dump.py | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/meta/lib/oeqa/utils/dump.py b/meta/lib/oeqa/utils/dump.py
index d34e05e2b4b..6594e286a49 100644
--- a/meta/lib/oeqa/utils/dump.py
+++ b/meta/lib/oeqa/utils/dump.py
@@ -71,8 +71,10 @@ 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'
         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):
-- 
2.20.1

[PATCH 2/5] oeqa: qemu: fix width of top output in host dump

[Paul Eggleton]

If runqemu fails, there is some logic to run a set of commands to dump
various bits of information that might help debug the issue
(particularly in a busy situation such as on the autobuilder). One of
those commands is "top -bn1", however top restricts the output to the
width of the calling terminal, and for whatever reason this is a little
restrictive when called from inside testimage, so set COLUMNS in the
environment to a high value to fix it. (Another way is to use the -w
option, but that is not supported by our default busybox configuration
so it will then fail when this same list of commands is used on the
target).

Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.com>
---
 meta/lib/oeqa/utils/dump.py | 1 +
 1 file changed, 1 insertion(+)

diff --git a/meta/lib/oeqa/utils/dump.py b/meta/lib/oeqa/utils/dump.py
index 6594e286a49..09a44329e01 100644
--- a/meta/lib/oeqa/utils/dump.py
+++ b/meta/lib/oeqa/utils/dump.py
@@ -73,6 +73,7 @@ class HostDumper(BaseDumper):
             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, env=env)
             self._write_dump(cmd.split()[0], result.output)
-- 
2.20.1

[PATCH 3/5] oeqa: qemu: ensure we print runqemu output in the event of failure

[Paul Eggleton]

If we get here in the code it's because runqemu has failed, this is not
a debug situation - we need to see the output, so print it as an error.

Fixes [YOCTO #13681].

Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.com>
---
 meta/lib/oeqa/utils/qemurunner.py | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/meta/lib/oeqa/utils/qemurunner.py b/meta/lib/oeqa/utils/qemurunner.py
index 60e1cf8e08e..2cada35d480 100644
--- a/meta/lib/oeqa/utils/qemurunner.py
+++ b/meta/lib/oeqa/utils/qemurunner.py
@@ -99,8 +99,8 @@ class QemuRunner:
     def handleSIGCHLD(self, signum, frame):
         if self.runqemu and self.runqemu.poll():
             if self.runqemu.returncode:
-                self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
-                self.logger.debug("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
-- 
2.20.1

[PATCH 4/5] runqemu: log parameters correctly within testimage

[Paul Eggleton]

It is not a good idea to mix logging and calls to print() - if the
output is being captured the result can be that the two types of output
are not recorded contiguously; this could be observed if an error
occurred running runqemu from inside testimage:

---------- snip ----------
ERROR: core-image-minimal-1.0-r0 do_testimage: Output from runqemu:
runqemu - INFO - Continuing with the following parameters:

runqemu - INFO - Setting up tap interface under sudo
sudo: a terminal is required to read the password; either use the -S option to read from standard input or configure an askpass helper
runqemu - ERROR - Setting up tap device failed:
Command '('sudo', '/home/paul/poky/poky/scripts/runqemu-ifup', '1000', '1000', '/home/paul/poky/poky/build/tmp/work/x86_64-linux/qemu-helper-native/1.0-r1/recipe-sysroot-native/usr/bin')' returned non-zero exit status 1.
Run runqemu-gen-tapdevs to manually create one.
runqemu - INFO - Cleaning up
KERNEL: [/home/paul/poky/poky/build/tmp/deploy/images/qemux86-64/bzImage--5.2.20+git0+bd0762cd13_dd25a04fc5-r0-qemux86-64-20191205213021.bin]
MACHINE: [qemux86-64]
FSTYPE: [ext4]
ROOTFS: [/home/paul/poky/poky/build/tmp/deploy/images/qemux86-64/core-image-minimal-qemux86-64.ext4]
CONFFILE: [/home/paul/poky/poky/build/tmp/deploy/images/qemux86-64/core-image-minimal-qemux86-64.qemuboot.conf]
---------- snip ----------

What we should see here is the KERNEL, MACHINE, etc. lines appearing
immediately after the "Continuing with the following parameters:" line
as they do when you run runqemu directly. If we put all of the lines
through the logger instead then it works properly.

Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.com>
---
 scripts/runqemu | 25 +++++++++++++------------
 1 file changed, 13 insertions(+), 12 deletions(-)

diff --git a/scripts/runqemu b/scripts/runqemu
index 5c56c3fe6c1..f061917c4b3 100755
--- a/scripts/runqemu
+++ b/scripts/runqemu
@@ -933,29 +933,30 @@ class BaseConfig(object):
                     self.set('STAGING_BINDIR_NATIVE', '%s/usr/bin' % self.get('STAGING_DIR_NATIVE'))
 
     def print_config(self):
-        logger.info('Continuing with the following parameters:\n')
+        logoutput = ['Continuing with the following parameters:']
         if not self.fstype in self.vmtypes:
-            print('KERNEL: [%s]' % self.kernel)
+            logoutput.append('KERNEL: [%s]' % self.kernel)
             if self.bios:
-                print('BIOS: [%s]' % self.bios)
+                logoutput.append('BIOS: [%s]' % self.bios)
             if self.dtb:
-                print('DTB: [%s]' % self.dtb)
-        print('MACHINE: [%s]' % self.get('MACHINE'))
+                logoutput.append('DTB: [%s]' % self.dtb)
+        logoutput.append('MACHINE: [%s]' % self.get('MACHINE'))
         try:
             fstype_flags = ' (' + ', '.join(self.fsinfo[self.fstype]) + ')'
         except KeyError:
             fstype_flags = ''
-        print('FSTYPE: [%s%s]' % (self.fstype, fstype_flags))
+        logoutput.append('FSTYPE: [%s%s]' % (self.fstype, fstype_flags))
         if self.fstype  == 'nfs':
-            print('NFS_DIR: [%s]' % self.rootfs)
+            logoutput.append('NFS_DIR: [%s]' % self.rootfs)
         else:
-            print('ROOTFS: [%s]' % self.rootfs)
+            logoutput.append('ROOTFS: [%s]' % self.rootfs)
         if self.ovmf_bios:
-            print('OVMF: %s' % self.ovmf_bios)
+            logoutput.append('OVMF: %s' % self.ovmf_bios)
         if (self.ovmf_secboot_pkkek1):
-            print('SECBOOT PKKEK1: [%s...]' % self.ovmf_secboot_pkkek1[0:100])
-        print('CONFFILE: [%s]' % self.qemuboot)
-        print('')
+            logoutput.append('SECBOOT PKKEK1: [%s...]' % self.ovmf_secboot_pkkek1[0:100])
+        logoutput.append('CONFFILE: [%s]' % self.qemuboot)
+        logoutput.append('')
+        logger.info('\n'.join(logoutput))
 
     def setup_nfs(self):
         if not self.nfs_server:
-- 
2.20.1

[PATCH 5/5] runqemu: handle tap device creation failure properly

[Paul Eggleton]

If we fail to run the command to generate the tap devices then we should
show a reasonable message and then exit, without showing a traceback.
"return 1" at this point in the code does nothing because the caller
doesn't check the return, so just use sys.exit().

Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.com>
---
 scripts/runqemu | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)

diff --git a/scripts/runqemu b/scripts/runqemu
index f061917c4b3..ef454d67ffd 100755
--- a/scripts/runqemu
+++ b/scripts/runqemu
@@ -1121,7 +1121,11 @@ class BaseConfig(object):
             uid = os.getuid()
             logger.info("Setting up tap interface under sudo")
             cmd = ('sudo', self.qemuifup, str(uid), str(gid), self.bindir_native)
-            tap = subprocess.check_output(cmd).decode('utf-8').strip()
+            try:
+                tap = subprocess.check_output(cmd).decode('utf-8').strip()
+            except subprocess.CalledProcessError as e:
+                logger.error('Setting up tap device failed:\n%s\nRun runqemu-gen-tapdevs to manually create one.' % str(e))
+                sys.exit(1)
             lockfile = os.path.join(lockdir, tap)
             self.taplock = lockfile + '.lock'
             self.acquire_taplock()
@@ -1130,7 +1134,7 @@ class BaseConfig(object):
 
         if not tap:
             logger.error("Failed to setup tap device. Run runqemu-gen-tapdevs to manually create.")
-            return 1
+            sys.exit(1)
         self.tap = tap
         tapnum = int(tap[3:])
         gateway = tapnum * 2 + 1
-- 
2.20.1