2 files changed, 94 insertions, 27 deletions

diff --git a/meta/lib/oeqa/core/target/qemu.py b/meta/lib/oeqa/core/target/qemu.py
index 0f29414df5..d93b3ac94a 100644
--- a/meta/lib/oeqa/core/target/qemu.py
+++ b/meta/lib/oeqa/core/target/qemu.py
@@ -8,20 +8,21 @@ import os
 import sys
 import signal
 import time
+import glob
+import subprocess
 from collections import defaultdict
 
 from .ssh import OESSHTarget
 from oeqa.utils.qemurunner import QemuRunner
-from oeqa.utils.dump import TargetDumper
 
 supported_fstypes = ['ext3', 'ext4', 'cpio.gz', 'wic']
 
 class OEQemuTarget(OESSHTarget):
     def __init__(self, logger, server_ip, timeout=300, user='root',
             port=None, machine='', rootfs='', kernel='', kvm=False, slirp=False,
-            dump_dir='', dump_host_cmds='', display='', bootlog='',
+            dump_dir='', display='', bootlog='',
             tmpdir='', dir_image='', boottime=60, serial_ports=2,
-            boot_patterns = defaultdict(str), ovmf=False, **kwargs):
+            boot_patterns = defaultdict(str), ovmf=False, tmpfsdir=None, **kwargs):
 
         super(OEQemuTarget, self).__init__(logger, None, server_ip, timeout,
                 user, port)
@@ -35,17 +36,15 @@ class OEQemuTarget(OESSHTarget):
         self.ovmf = ovmf
         self.use_slirp = slirp
         self.boot_patterns = boot_patterns
+        self.dump_dir = dump_dir
+        self.bootlog = bootlog
 
         self.runner = QemuRunner(machine=machine, rootfs=rootfs, tmpdir=tmpdir,
                                  deploy_dir_image=dir_image, display=display,
                                  logfile=bootlog, boottime=boottime,
-                                 use_kvm=kvm, use_slirp=slirp, dump_dir=dump_dir,
-                                 dump_host_cmds=dump_host_cmds, logger=logger,
+                                 use_kvm=kvm, use_slirp=slirp, dump_dir=dump_dir, logger=logger,
                                  serial_ports=serial_ports, boot_patterns = boot_patterns, 
-                                 use_ovmf=ovmf)
-        dump_target_cmds = kwargs.get("testimage_dump_target")
-        self.target_dumper = TargetDumper(dump_target_cmds, dump_dir, self.runner)
-        self.target_dumper.create_dir("qemu")
+                                 use_ovmf=ovmf, tmpfsdir=tmpfsdir)
 
     def start(self, params=None, extra_bootparams=None, runqemuparams=''):
         if self.use_slirp and not self.server_ip:
@@ -68,7 +67,28 @@ class OEQemuTarget(OESSHTarget):
                 self.server_ip = self.runner.server_ip
         else:
             self.stop()
-            raise RuntimeError("FAILED to start qemu - check the task log and the boot log")
+            # Display the first 20 lines of top and
+            # last 20 lines of the bootlog when the
+            # target is not being booted up.
+            topfile = glob.glob(self.dump_dir + "/*_qemu/host_*_top")
+            msg = "\n\n===== start: snippet =====\n\n"
+            for f in topfile:
+                msg += "file: %s\n\n" % f
+                with open(f) as tf:
+                    for x in range(20):
+                        msg += next(tf)
+            msg += "\n\n===== end: snippet =====\n\n"
+            blcmd = ["tail", "-20", self.bootlog]
+            msg += "===== start: snippet =====\n\n"
+            try:
+                out = subprocess.check_output(blcmd, stderr=subprocess.STDOUT, timeout=1).decode('utf-8')
+                msg += "file: %s\n\n" % self.bootlog
+                msg += out
+            except (subprocess.CalledProcessError, subprocess.TimeoutExpired, FileNotFoundError) as err:
+                msg += "Error running command: %s\n%s\n" % (blcmd, err)
+            msg += "\n\n===== end: snippet =====\n"
+
+            raise RuntimeError("FAILED to start qemu - check the task log and the boot log %s" % (msg))
 
     def stop(self):
         self.runner.stop()
diff --git a/meta/lib/oeqa/core/target/ssh.py b/meta/lib/oeqa/core/target/ssh.py
index 461448dbc5..09cdd14c75 100644
--- a/meta/lib/oeqa/core/target/ssh.py
+++ b/meta/lib/oeqa/core/target/ssh.py
@@ -34,12 +34,17 @@ class OESSHTarget(OETarget):
         self.timeout = timeout
         self.user = user
         ssh_options = [
+                '-o', 'ServerAliveCountMax=2',
+                '-o', 'ServerAliveInterval=30',
                 '-o', 'UserKnownHostsFile=/dev/null',
                 '-o', 'StrictHostKeyChecking=no',
                 '-o', 'LogLevel=ERROR'
                 ]
+        scp_options = [
+                '-r'
+        ]
         self.ssh = ['ssh', '-l', self.user ] + ssh_options
-        self.scp = ['scp'] + ssh_options
+        self.scp = ['scp'] + ssh_options + scp_options
         if port:
             self.ssh = self.ssh + [ '-p', port ]
             self.scp = self.scp + [ '-P', port ]
@@ -67,7 +72,7 @@ class OESSHTarget(OETarget):
 
         return (status, output)
 
-    def run(self, command, timeout=None):
+    def run(self, command, timeout=None, ignore_status=True):
         """
             Runs command in target.
 
@@ -86,10 +91,9 @@ class OESSHTarget(OETarget):
         else:
             processTimeout = self.timeout
 
-        status, output = self._run(sshCmd, processTimeout, True)
-        self.logger.debug('Command: %s\nOutput:  %s\n' % (command, output))
-        if (status == 255) and (('No route to host') in output):
-            self.target_dumper.dump_target()
+        status, output = self._run(sshCmd, processTimeout, ignore_status)
+        self.logger.debug('Command: %s\nStatus: %d Output:  %s\n' % (command, status, output))
+
         return (status, output)
 
     def copyTo(self, localSrc, remoteDst):
@@ -207,27 +211,41 @@ def SSHCall(command, logger, timeout=None, **opts):
     def run():
         nonlocal output
         nonlocal process
+        output_raw = b''
         starttime = time.time()
         process = subprocess.Popen(command, **options)
+        has_timeout = False
         if timeout:
             endtime = starttime + timeout
             eof = False
-            while time.time() < endtime and not eof:
-                logger.debug('time: %s, endtime: %s' % (time.time(), endtime))
+            os.set_blocking(process.stdout.fileno(), False)
+            while not has_timeout and not eof:
                 try:
+                    logger.debug('Waiting for process output: time: %s, endtime: %s' % (time.time(), endtime))
                     if select.select([process.stdout], [], [], 5)[0] != []:
-                        reader = codecs.getreader('utf-8')(process.stdout, 'ignore')
-                        data = reader.read(1024, 4096)
+                        # wait a bit for more data, tries to avoid reading single characters
+                        time.sleep(0.2)
+                        data = process.stdout.read()
                         if not data:
-                            process.stdout.close()
                             eof = True
                         else:
-                            output += data
-                            logger.debug('Partial data from SSH call: %s' % data)
+                            output_raw += data
+                            # ignore errors to capture as much as possible
+                            logger.debug('Partial data from SSH call:\n%s' % data.decode('utf-8', errors='ignore'))
                             endtime = time.time() + timeout
                 except InterruptedError:
+                    logger.debug('InterruptedError')
+                    continue
+                except BlockingIOError:
+                    logger.debug('BlockingIOError')
                     continue
 
+                if time.time() >= endtime:
+                    logger.debug('SSHCall has timeout! Time: %s, endtime: %s' % (time.time(), endtime))
+                    has_timeout = True
+
+            process.stdout.close()
+
             # process hasn't returned yet
             if not eof:
                 process.terminate()
@@ -235,16 +253,42 @@ def SSHCall(command, logger, timeout=None, **opts):
                 try:
                     process.kill()
                 except OSError:
+                    logger.debug('OSError when killing process')
                     pass
                 endtime = time.time() - starttime
                 lastline = ("\nProcess killed - no output for %d seconds. Total"
                             " running time: %d seconds." % (timeout, endtime))
-                logger.debug('Received data from SSH call %s ' % lastline)
+                logger.debug('Received data from SSH call:\n%s ' % lastline)
                 output += lastline
+                process.wait()
 
         else:
-            output = process.communicate()[0].decode('utf-8', errors='ignore')
-            logger.debug('Data from SSH call: %s' % output.rstrip())
+            output_raw = process.communicate()[0]
+
+        output = output_raw.decode('utf-8', errors='ignore')
+        logger.debug('Data from SSH call:\n%s' % output.rstrip())
+
+        # timout or not, make sure process exits and is not hanging
+        if process.returncode == None:
+            try:
+                process.wait(timeout=5)
+            except TimeoutExpired:
+                try:
+                    process.kill()
+                except OSError:
+                    logger.debug('OSError')
+                    pass
+                process.wait()
+
+        if has_timeout:
+            # Version of openssh before 8.6_p1 returns error code 0 when killed
+            # by a signal, when the timeout occurs we will receive a 0 error
+            # code because the process is been terminated and it's wrong because
+            # that value means success, but the process timed out.
+            # Afterwards, from version 8.6_p1 onwards, the returned code is 255.
+            # Fix this behaviour by checking the return code
+            if process.returncode == 0:
+                process.returncode = 255
 
     options = {
         "stdout": subprocess.PIPE,
@@ -271,6 +315,9 @@ def SSHCall(command, logger, timeout=None, **opts):
         # whilst running and ensure we don't leave a process behind.
         if process.poll() is None:
             process.kill()
+        if process.returncode == None:
+            process.wait()
         logger.debug('Something went wrong, killing SSH process')
         raise
-    return (process.wait(), output.rstrip())
+
+    return (process.returncode, output.rstrip())