1#
2# Copyright (C) 2013 Intel Corporation
3#
4# SPDX-License-Identifier: MIT
5#
6
7# This module provides a class for starting qemu images using runqemu.
8# It's used by testimage.bbclass.
9
10import subprocess
11import os
12import sys
13import time
14import signal
15import re
16import socket
17import select
18import errno
19import string
20import threading
21import codecs
22import logging
23import tempfile
24from oeqa.utils.dump import HostDumper
25from collections import defaultdict
26import importlib
27
28# Get Unicode non printable control chars
29control_range = list(range(0,32))+list(range(127,160))
30control_chars = [chr(x) for x in control_range
31                if chr(x) not in string.printable]
32re_control_char = re.compile('[%s]' % re.escape("".join(control_chars)))
33
34class QemuRunner:
35
36    def __init__(self, machine, rootfs, display, tmpdir, deploy_dir_image, logfile, boottime, dump_dir, dump_host_cmds,
37                 use_kvm, logger, use_slirp=False, serial_ports=2, boot_patterns = defaultdict(str), use_ovmf=False, workdir=None, tmpfsdir=None):
38
39        # Popen object for runqemu
40        self.runqemu = None
41        self.runqemu_exited = False
42        # pid of the qemu process that runqemu will start
43        self.qemupid = None
44        # target ip - from the command line or runqemu output
45        self.ip = None
46        # host ip - where qemu is running
47        self.server_ip = None
48        # target ip netmask
49        self.netmask = None
50
51        self.machine = machine
52        self.rootfs = rootfs
53        self.display = display
54        self.tmpdir = tmpdir
55        self.deploy_dir_image = deploy_dir_image
56        self.logfile = logfile
57        self.boottime = boottime
58        self.logged = False
59        self.thread = None
60        self.use_kvm = use_kvm
61        self.use_ovmf = use_ovmf
62        self.use_slirp = use_slirp
63        self.serial_ports = serial_ports
64        self.msg = ''
65        self.boot_patterns = boot_patterns
66        self.tmpfsdir = tmpfsdir
67
68        self.runqemutime = 300
69        if not workdir:
70            workdir = os.getcwd()
71        self.qemu_pidfile = workdir + '/pidfile_' + str(os.getpid())
72        self.host_dumper = HostDumper(dump_host_cmds, dump_dir)
73        self.monitorpipe = None
74
75        self.logger = logger
76        # Whether we're expecting an exit and should show related errors
77        self.canexit = False
78
79        # Enable testing other OS's
80        # Set commands for target communication, and default to Linux ALWAYS
81        # Other OS's or baremetal applications need to provide their
82        # own implementation passing it through QemuRunner's constructor
83        # or by passing them through TESTIMAGE_BOOT_PATTERNS[flag]
84        # provided variables, where <flag> is one of the mentioned below.
85        accepted_patterns = ['search_reached_prompt', 'send_login_user', 'search_login_succeeded', 'search_cmd_finished']
86        default_boot_patterns = defaultdict(str)
87        # Default to the usual paterns used to communicate with the target
88        default_boot_patterns['search_reached_prompt'] = ' login:'
89        default_boot_patterns['send_login_user'] = 'root\n'
90        default_boot_patterns['search_login_succeeded'] = r"root@[a-zA-Z0-9\-]+:~#"
91        default_boot_patterns['search_cmd_finished'] = r"[a-zA-Z0-9]+@[a-zA-Z0-9\-]+:~#"
92
93        # Only override patterns that were set e.g. login user TESTIMAGE_BOOT_PATTERNS[send_login_user] = "webserver\n"
94        for pattern in accepted_patterns:
95            if not self.boot_patterns[pattern]:
96                self.boot_patterns[pattern] = default_boot_patterns[pattern]
97
98    def create_socket(self):
99        try:
100            sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
101            sock.setblocking(0)
102            sock.bind(("127.0.0.1",0))
103            sock.listen(2)
104            port = sock.getsockname()[1]
105            self.logger.debug("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port)
106            return (sock, port)
107
108        except socket.error:
109            sock.close()
110            raise
111
112    def decode_qemulog(self, todecode):
113        # Sanitize the data received from qemu as it may contain control characters
114        msg = todecode.decode("utf-8", errors='ignore')
115        msg = re_control_char.sub('', msg)
116        return msg
117
118    def log(self, msg):
119        if self.logfile:
120            msg = self.decode_qemulog(msg)
121            self.msg += msg
122            with codecs.open(self.logfile, "a", encoding="utf-8") as f:
123                f.write("%s" % msg)
124
125    def getOutput(self, o):
126        import fcntl
127        fl = fcntl.fcntl(o, fcntl.F_GETFL)
128        fcntl.fcntl(o, fcntl.F_SETFL, fl | os.O_NONBLOCK)
129        try:
130            return os.read(o.fileno(), 1000000).decode("utf-8")
131        except BlockingIOError:
132            return ""
133
134
135    def handleSIGCHLD(self, signum, frame):
136        if self.runqemu and self.runqemu.poll():
137            if self.runqemu.returncode:
138                self.logger.error('runqemu exited with code %d' % self.runqemu.returncode)
139                self.logger.error('Output from runqemu:\n%s' % self.getOutput(self.runqemu.stdout))
140                self.stop()
141                self._dump_host()
142
143    def start(self, qemuparams = None, get_ip = True, extra_bootparams = None, runqemuparams='', launch_cmd=None, discard_writes=True):
144        env = os.environ.copy()
145        if self.display:
146            env["DISPLAY"] = self.display
147            # Set this flag so that Qemu doesn't do any grabs as SDL grabs
148            # interact badly with screensavers.
149            env["QEMU_DONT_GRAB"] = "1"
150        if not os.path.exists(self.rootfs):
151            self.logger.error("Invalid rootfs %s" % self.rootfs)
152            return False
153        if not os.path.exists(self.tmpdir):
154            self.logger.error("Invalid TMPDIR path %s" % self.tmpdir)
155            return False
156        else:
157            env["OE_TMPDIR"] = self.tmpdir
158        if not os.path.exists(self.deploy_dir_image):
159            self.logger.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image)
160            return False
161        else:
162            env["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image
163
164        if self.tmpfsdir:
165            env["RUNQEMU_TMPFS_DIR"] = self.tmpfsdir
166
167        if not launch_cmd:
168            launch_cmd = 'runqemu %s' % ('snapshot' if discard_writes else '')
169            if self.use_kvm:
170                self.logger.debug('Using kvm for runqemu')
171                launch_cmd += ' kvm'
172            else:
173                self.logger.debug('Not using kvm for runqemu')
174            if not self.display:
175                launch_cmd += ' nographic'
176            if self.use_slirp:
177                launch_cmd += ' slirp'
178            if self.use_ovmf:
179                launch_cmd += ' ovmf'
180            launch_cmd += ' %s %s' % (runqemuparams, self.machine)
181            if self.rootfs.endswith('.vmdk'):
182                self.logger.debug('Bypassing VMDK rootfs for runqemu')
183            else:
184                launch_cmd += ' %s' % (self.rootfs)
185
186        return self.launch(launch_cmd, qemuparams=qemuparams, get_ip=get_ip, extra_bootparams=extra_bootparams, env=env)
187
188    def launch(self, launch_cmd, get_ip = True, qemuparams = None, extra_bootparams = None, env = None):
189        # use logfile to determine the recipe-sysroot-native path and
190        # then add in the site-packages path components and add that
191        # to the python sys.path so qmp.py can be found.
192        python_path = os.path.dirname(os.path.dirname(self.logfile))
193        python_path += "/recipe-sysroot-native/usr/lib/qemu-python"
194        sys.path.append(python_path)
195        importlib.invalidate_caches()
196        try:
197            qmp = importlib.import_module("qmp")
198        except Exception as e:
199            self.logger.error("qemurunner: qmp.py missing, please ensure it's installed (%s)" % str(e))
200            return False
201        # Path relative to tmpdir used as cwd for qemu below to avoid unix socket path length issues
202        qmp_file = "." + next(tempfile._get_candidate_names())
203        qmp_param = ' -S -qmp unix:./%s,server,wait' % (qmp_file)
204        qmp_port = self.tmpdir + "/" + qmp_file
205        # Create a second socket connection for debugging use,
206        # note this will NOT cause qemu to block waiting for the connection
207        qmp_file2 = "." + next(tempfile._get_candidate_names())
208        qmp_param += ' -qmp unix:./%s,server,nowait' % (qmp_file2)
209        qmp_port2 = self.tmpdir + "/" + qmp_file2
210        self.logger.info("QMP Available for connection at %s" % (qmp_port2))
211
212        try:
213            if self.serial_ports >= 2:
214                self.threadsock, threadport = self.create_socket()
215            self.server_socket, self.serverport = self.create_socket()
216        except socket.error as msg:
217            self.logger.error("Failed to create listening socket: %s" % msg[1])
218            return False
219
220        bootparams = ' printk.time=1'
221        if extra_bootparams:
222            bootparams = bootparams + ' ' + extra_bootparams
223
224        # Ask QEMU to store the QEMU process PID in file, this way we don't have to parse running processes
225        # and analyze descendents in order to determine it.
226        if os.path.exists(self.qemu_pidfile):
227            os.remove(self.qemu_pidfile)
228        self.qemuparams = 'bootparams="{0}" qemuparams="-pidfile {1} {2}"'.format(bootparams, self.qemu_pidfile, qmp_param)
229
230        if qemuparams:
231            self.qemuparams = self.qemuparams[:-1] + " " + qemuparams + " " + '\"'
232
233        if self.serial_ports >= 2:
234            launch_cmd += ' tcpserial=%s:%s %s' % (threadport, self.serverport, self.qemuparams)
235        else:
236            launch_cmd += ' tcpserial=%s %s' % (self.serverport, self.qemuparams)
237
238        self.origchldhandler = signal.getsignal(signal.SIGCHLD)
239        signal.signal(signal.SIGCHLD, self.handleSIGCHLD)
240
241        self.logger.debug('launchcmd=%s'%(launch_cmd))
242
243        # FIXME: We pass in stdin=subprocess.PIPE here to work around stty
244        # blocking at the end of the runqemu script when using this within
245        # oe-selftest (this makes stty error out immediately). There ought
246        # to be a proper fix but this will suffice for now.
247        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)
248        output = self.runqemu.stdout
249        launch_time = time.time()
250
251        #
252        # We need the preexec_fn above so that all runqemu processes can easily be killed
253        # (by killing their process group). This presents a problem if this controlling
254        # process itself is killed however since those processes don't notice the death
255        # of the parent and merrily continue on.
256        #
257        # Rather than hack runqemu to deal with this, we add something here instead.
258        # Basically we fork off another process which holds an open pipe to the parent
259        # and also is setpgrp. If/when the pipe sees EOF from the parent dieing, it kills
260        # the process group. This is like pctrl's PDEATHSIG but for a process group
261        # rather than a single process.
262        #
263        r, w = os.pipe()
264        self.monitorpid = os.fork()
265        if self.monitorpid:
266            os.close(r)
267            self.monitorpipe = os.fdopen(w, "w")
268        else:
269            # child process
270            os.setpgrp()
271            os.close(w)
272            r = os.fdopen(r)
273            x = r.read()
274            os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
275            os._exit(0)
276
277        self.logger.debug("runqemu started, pid is %s" % self.runqemu.pid)
278        self.logger.debug("waiting at most %s seconds for qemu pid (%s)" %
279                          (self.runqemutime, time.strftime("%D %H:%M:%S")))
280        endtime = time.time() + self.runqemutime
281        while not self.is_alive() and time.time() < endtime:
282            if self.runqemu.poll():
283                if self.runqemu_exited:
284                    self.logger.warning("runqemu during is_alive() test")
285                    return False
286                if self.runqemu.returncode:
287                    # No point waiting any longer
288                    self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
289                    self._dump_host()
290                    self.logger.warning("Output from runqemu:\n%s" % self.getOutput(output))
291                    self.stop()
292                    return False
293            time.sleep(0.5)
294
295        if self.runqemu_exited:
296            self.logger.warning("runqemu after timeout")
297
298        if self.runqemu.returncode:
299            self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
300
301        if not self.is_alive():
302            self.logger.error("Qemu pid didn't appear in %s seconds (%s)" %
303                              (self.runqemutime, time.strftime("%D %H:%M:%S")))
304
305            qemu_pid = None
306            if os.path.isfile(self.qemu_pidfile):
307                with open(self.qemu_pidfile, 'r') as f:
308                    qemu_pid = f.read().strip()
309
310            self.logger.error("Status information, poll status: %s, pidfile exists: %s, pidfile contents %s, proc pid exists %s"
311                % (self.runqemu.poll(), os.path.isfile(self.qemu_pidfile), str(qemu_pid), os.path.exists("/proc/" + str(qemu_pid))))
312
313            # Dump all processes to help us to figure out what is going on...
314            ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,pri,ni,command '], stdout=subprocess.PIPE).communicate()[0]
315            processes = ps.decode("utf-8")
316            self.logger.debug("Running processes:\n%s" % processes)
317            self._dump_host()
318            op = self.getOutput(output)
319            self.stop()
320            if op:
321                self.logger.error("Output from runqemu:\n%s" % op)
322            else:
323                self.logger.error("No output from runqemu.\n")
324            return False
325
326        # Create the client socket for the QEMU Monitor Control Socket
327        # This will allow us to read status from Qemu if the the process
328        # is still alive
329        self.logger.debug("QMP Initializing to %s" % (qmp_port))
330        # chdir dance for path length issues with unix sockets
331        origpath = os.getcwd()
332        try:
333            os.chdir(os.path.dirname(qmp_port))
334            try:
335               from qmp.legacy import QEMUMonitorProtocol
336               self.qmp = QEMUMonitorProtocol(os.path.basename(qmp_port))
337            except OSError as msg:
338                self.logger.warning("Failed to initialize qemu monitor socket: %s File: %s" % (msg, msg.filename))
339                return False
340
341            self.logger.debug("QMP Connecting to %s" % (qmp_port))
342            if not os.path.exists(qmp_port) and self.is_alive():
343                self.logger.debug("QMP Port does not exist waiting for it to be created")
344                endtime = time.time() + self.runqemutime
345                while not os.path.exists(qmp_port) and self.is_alive() and time.time() < endtime:
346                   self.logger.info("QMP port does not exist yet!")
347                   time.sleep(0.5)
348                if not os.path.exists(qmp_port) and self.is_alive():
349                    self.logger.warning("QMP Port still does not exist but QEMU is alive")
350                    return False
351
352            try:
353                self.qmp.connect()
354                connect_time = time.time()
355                self.logger.info("QMP connected to QEMU at %s and took %s seconds" %
356                                  (time.strftime("%D %H:%M:%S"),
357                                   time.time() - launch_time))
358            except OSError as msg:
359                self.logger.warning("Failed to connect qemu monitor socket: %s File: %s" % (msg, msg.filename))
360                return False
361            except qmp.legacy.QMPError as msg:
362                self.logger.warning("Failed to communicate with qemu monitor: %s" % (msg))
363                return False
364        finally:
365            os.chdir(origpath)
366
367        # We worry that mmap'd libraries may cause page faults which hang the qemu VM for periods
368        # causing failures. Before we "start" qemu, read through it's mapped files to try and
369        # ensure we don't hit page faults later
370        mapdir = "/proc/" + str(self.qemupid) + "/map_files/"
371        try:
372            for f in os.listdir(mapdir):
373                try:
374                    linktarget = os.readlink(os.path.join(mapdir, f))
375                    if not linktarget.startswith("/") or linktarget.startswith("/dev") or "deleted" in linktarget:
376                        continue
377                    with open(linktarget, "rb") as readf:
378                        data = True
379                        while data:
380                            data = readf.read(4096)
381                except FileNotFoundError:
382                    continue
383        # Centos7 doesn't allow us to read /map_files/
384        except PermissionError:
385            pass
386
387        # Release the qemu process to continue running
388        self.run_monitor('cont')
389        self.logger.info("QMP released QEMU at %s and took %s seconds from connect" %
390                          (time.strftime("%D %H:%M:%S"),
391                           time.time() - connect_time))
392
393        # We are alive: qemu is running
394        out = self.getOutput(output)
395        netconf = False # network configuration is not required by default
396        self.logger.debug("qemu started in %s seconds - qemu procces pid is %s (%s)" %
397                          (time.time() - (endtime - self.runqemutime),
398                           self.qemupid, time.strftime("%D %H:%M:%S")))
399        cmdline = ''
400        if get_ip:
401            with open('/proc/%s/cmdline' % self.qemupid) as p:
402                cmdline = p.read()
403                # It is needed to sanitize the data received
404                # because is possible to have control characters
405                cmdline = re_control_char.sub(' ', cmdline)
406            try:
407                if self.use_slirp:
408                    tcp_ports = cmdline.split("hostfwd=tcp:")[1]
409                    ip, tcp_ports = tcp_ports.split(":")[:2]
410                    host_port = tcp_ports[:tcp_ports.find('-')]
411                    self.ip = "%s:%s" % (ip, host_port)
412                else:
413                    ips = re.findall(r"((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1])
414                    self.ip = ips[0]
415                    self.server_ip = ips[1]
416                self.logger.debug("qemu cmdline used:\n{}".format(cmdline))
417            except (IndexError, ValueError):
418                # Try to get network configuration from runqemu output
419                match = re.match(r'.*Network configuration: (?:ip=)*([0-9.]+)::([0-9.]+):([0-9.]+).*',
420                                 out, re.MULTILINE|re.DOTALL)
421                if match:
422                    self.ip, self.server_ip, self.netmask = match.groups()
423                    # network configuration is required as we couldn't get it
424                    # from the runqemu command line, so qemu doesn't run kernel
425                    # and guest networking is not configured
426                    netconf = True
427                else:
428                    self.logger.error("Couldn't get ip from qemu command line and runqemu output! "
429                                 "Here is the qemu command line used:\n%s\n"
430                                 "and output from runqemu:\n%s" % (cmdline, out))
431                    self._dump_host()
432                    self.stop()
433                    return False
434
435        self.logger.debug("Target IP: %s" % self.ip)
436        self.logger.debug("Server IP: %s" % self.server_ip)
437
438        if self.serial_ports >= 2:
439            self.thread = LoggingThread(self.log, self.threadsock, self.logger)
440            self.thread.start()
441            if not self.thread.connection_established.wait(self.boottime):
442                self.logger.error("Didn't receive a console connection from qemu. "
443                             "Here is the qemu command line used:\n%s\nand "
444                             "output from runqemu:\n%s" % (cmdline, out))
445                self.stop_thread()
446                return False
447
448        self.logger.debug("Output from runqemu:\n%s", out)
449        self.logger.debug("Waiting at most %d seconds for login banner (%s)" %
450                          (self.boottime, time.strftime("%D %H:%M:%S")))
451        endtime = time.time() + self.boottime
452        socklist = [self.server_socket]
453        reachedlogin = False
454        stopread = False
455        qemusock = None
456        bootlog = b''
457        data = b''
458        while time.time() < endtime and not stopread:
459            try:
460                sread, swrite, serror = select.select(socklist, [], [], 5)
461            except InterruptedError:
462                continue
463            for sock in sread:
464                if sock is self.server_socket:
465                    qemusock, addr = self.server_socket.accept()
466                    qemusock.setblocking(0)
467                    socklist.append(qemusock)
468                    socklist.remove(self.server_socket)
469                    self.logger.debug("Connection from %s:%s" % addr)
470                else:
471                    data = data + sock.recv(1024)
472                    if data:
473                        bootlog += data
474                        if self.serial_ports < 2:
475                            # this socket has mixed console/kernel data, log it to logfile
476                            self.log(data)
477
478                        data = b''
479
480                        decodedlog = self.decode_qemulog(bootlog)
481                        if self.boot_patterns['search_reached_prompt'] in decodedlog:
482                            self.server_socket = qemusock
483                            stopread = True
484                            reachedlogin = True
485                            self.logger.debug("Reached login banner in %s seconds (%s, %s)" %
486                                              (time.time() - (endtime - self.boottime),
487                                              time.strftime("%D %H:%M:%S"), time.time()))
488                    else:
489                        # no need to check if reachedlogin unless we support multiple connections
490                        self.logger.debug("QEMU socket disconnected before login banner reached. (%s)" %
491                                          time.strftime("%D %H:%M:%S"))
492                        socklist.remove(sock)
493                        sock.close()
494                        stopread = True
495
496        if not reachedlogin:
497            if time.time() >= endtime:
498                self.logger.warning("Target didn't reach login banner in %d seconds (%s)" %
499                                  (self.boottime, time.strftime("%D %H:%M:%S")))
500            tail = lambda l: "\n".join(l.splitlines()[-25:])
501            bootlog = self.decode_qemulog(bootlog)
502            # in case bootlog is empty, use tail qemu log store at self.msg
503            lines = tail(bootlog if bootlog else self.msg)
504            self.logger.warning("Last 25 lines of text (%d):\n%s" % (len(bootlog), lines))
505            self.logger.warning("Check full boot log: %s" % self.logfile)
506            self._dump_host()
507            self.stop()
508            return False
509
510        # If we are not able to login the tests can continue
511        try:
512            (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120)
513            if re.search(self.boot_patterns['search_login_succeeded'], output):
514                self.logged = True
515                self.logger.debug("Logged as root in serial console")
516                if netconf:
517                    # configure guest networking
518                    cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask)
519                    output = self.run_serial(cmd, raw=True)[1]
520                    if re.search(r"root@[a-zA-Z0-9\-]+:~#", output):
521                        self.logger.debug("configured ip address %s", self.ip)
522                    else:
523                        self.logger.debug("Couldn't configure guest networking")
524            else:
525                self.logger.warning("Couldn't login into serial console"
526                            " as root using blank password")
527                self.logger.warning("The output:\n%s" % output)
528        except:
529            self.logger.warning("Serial console failed while trying to login")
530        return True
531
532    def stop(self):
533        if hasattr(self, "origchldhandler"):
534            signal.signal(signal.SIGCHLD, self.origchldhandler)
535        self.stop_thread()
536        self.stop_qemu_system()
537        if self.runqemu:
538            if hasattr(self, "monitorpid"):
539                os.kill(self.monitorpid, signal.SIGKILL)
540                self.logger.debug("Sending SIGTERM to runqemu")
541                try:
542                    os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
543                except OSError as e:
544                    if e.errno != errno.ESRCH:
545                        raise
546            endtime = time.time() + self.runqemutime
547            while self.runqemu.poll() is None and time.time() < endtime:
548                time.sleep(1)
549            if self.runqemu.poll() is None:
550                self.logger.debug("Sending SIGKILL to runqemu")
551                os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL)
552            if not self.runqemu.stdout.closed:
553                self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout))
554            self.runqemu.stdin.close()
555            self.runqemu.stdout.close()
556            self.runqemu_exited = True
557
558        if hasattr(self, 'qmp') and self.qmp:
559            self.qmp.close()
560            self.qmp = None
561        if hasattr(self, 'server_socket') and self.server_socket:
562            self.server_socket.close()
563            self.server_socket = None
564        if hasattr(self, 'threadsock') and self.threadsock:
565            self.threadsock.close()
566            self.threadsock = None
567        self.qemupid = None
568        self.ip = None
569        if os.path.exists(self.qemu_pidfile):
570            try:
571                os.remove(self.qemu_pidfile)
572            except FileNotFoundError as e:
573                # We raced, ignore
574                pass
575        if self.monitorpipe:
576            self.monitorpipe.close()
577
578    def stop_qemu_system(self):
579        if self.qemupid:
580            try:
581                # qemu-system behaves well and a SIGTERM is enough
582                os.kill(self.qemupid, signal.SIGTERM)
583            except ProcessLookupError as e:
584                self.logger.warning('qemu-system ended unexpectedly')
585
586    def stop_thread(self):
587        if self.thread and self.thread.is_alive():
588            self.thread.stop()
589            self.thread.join()
590
591    def allowexit(self):
592        self.canexit = True
593        if self.thread:
594            self.thread.allowexit()
595
596    def restart(self, qemuparams = None):
597        self.logger.warning("Restarting qemu process")
598        if self.runqemu.poll() is None:
599            self.stop()
600        if self.start(qemuparams):
601            return True
602        return False
603
604    def is_alive(self):
605        if not self.runqemu or self.runqemu.poll() is not None or self.runqemu_exited:
606            return False
607        if os.path.isfile(self.qemu_pidfile):
608            # when handling pidfile, qemu creates the file, stat it, lock it and then write to it
609            # so it's possible that the file has been created but the content is empty
610            pidfile_timeout = time.time() + 3
611            while time.time() < pidfile_timeout:
612                with open(self.qemu_pidfile, 'r') as f:
613                    qemu_pid = f.read().strip()
614                # file created but not yet written contents
615                if not qemu_pid:
616                    time.sleep(0.5)
617                    continue
618                else:
619                    if os.path.exists("/proc/" + qemu_pid):
620                        self.qemupid = int(qemu_pid)
621                        return True
622        return False
623
624    def run_monitor(self, command, args=None, timeout=60):
625        if hasattr(self, 'qmp') and self.qmp:
626            if args is not None:
627                return self.qmp.cmd(command, args)
628            else:
629                return self.qmp.cmd(command)
630
631    def run_serial(self, command, raw=False, timeout=60):
632        # Returns (status, output) where status is 1 on success and 0 on error
633
634        # We assume target system have echo to get command status
635        if not raw:
636            command = "%s; echo $?\n" % command
637
638        data = ''
639        status = 0
640        self.server_socket.sendall(command.encode('utf-8'))
641        start = time.time()
642        end = start + timeout
643        while True:
644            now = time.time()
645            if now >= end:
646                data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout
647                break
648            try:
649                sread, _, _ = select.select([self.server_socket],[],[], end - now)
650            except InterruptedError:
651                continue
652            if sread:
653                answer = self.server_socket.recv(1024)
654                if answer:
655                    data += answer.decode('utf-8')
656                    # Search the prompt to stop
657                    if re.search(self.boot_patterns['search_cmd_finished'], data):
658                        break
659                else:
660                    if self.canexit:
661                        return (1, "")
662                    raise Exception("No data on serial console socket, connection closed?")
663
664        if data:
665            if raw:
666                status = 1
667            else:
668                # Remove first line (command line) and last line (prompt)
669                data = data[data.find('$?\r\n')+4:data.rfind('\r\n')]
670                index = data.rfind('\r\n')
671                if index == -1:
672                    status_cmd = data
673                    data = ""
674                else:
675                    status_cmd = data[index+2:]
676                    data = data[:index]
677                if (status_cmd == "0"):
678                    status = 1
679        return (status, str(data))
680
681
682    def _dump_host(self):
683        self.host_dumper.create_dir("qemu")
684        self.logger.warning("Qemu ended unexpectedly, dump data from host"
685                " is in %s" % self.host_dumper.dump_dir)
686        self.host_dumper.dump_host()
687
688# This class is for reading data from a socket and passing it to logfunc
689# to be processed. It's completely event driven and has a straightforward
690# event loop. The mechanism for stopping the thread is a simple pipe which
691# will wake up the poll and allow for tearing everything down.
692class LoggingThread(threading.Thread):
693    def __init__(self, logfunc, sock, logger):
694        self.connection_established = threading.Event()
695        self.serversock = sock
696        self.logfunc = logfunc
697        self.logger = logger
698        self.readsock = None
699        self.running = False
700        self.canexit = False
701
702        self.errorevents = select.POLLERR | select.POLLHUP | select.POLLNVAL
703        self.readevents = select.POLLIN | select.POLLPRI
704
705        threading.Thread.__init__(self, target=self.threadtarget)
706
707    def threadtarget(self):
708        try:
709            self.eventloop()
710        finally:
711            self.teardown()
712
713    def run(self):
714        self.logger.debug("Starting logging thread")
715        self.readpipe, self.writepipe = os.pipe()
716        threading.Thread.run(self)
717
718    def stop(self):
719        self.logger.debug("Stopping logging thread")
720        if self.running:
721            os.write(self.writepipe, bytes("stop", "utf-8"))
722
723    def teardown(self):
724        self.logger.debug("Tearing down logging thread")
725        self.close_socket(self.serversock)
726
727        if self.readsock is not None:
728            self.close_socket(self.readsock)
729
730        self.close_ignore_error(self.readpipe)
731        self.close_ignore_error(self.writepipe)
732        self.running = False
733
734    def allowexit(self):
735        self.canexit = True
736
737    def eventloop(self):
738        poll = select.poll()
739        event_read_mask = self.errorevents | self.readevents
740        poll.register(self.serversock.fileno())
741        poll.register(self.readpipe, event_read_mask)
742
743        breakout = False
744        self.running = True
745        self.logger.debug("Starting thread event loop")
746        while not breakout:
747            events = poll.poll()
748            for event in events:
749                # An error occurred, bail out
750                if event[1] & self.errorevents:
751                    raise Exception(self.stringify_event(event[1]))
752
753                # Event to stop the thread
754                if self.readpipe == event[0]:
755                    self.logger.debug("Stop event received")
756                    breakout = True
757                    break
758
759                # A connection request was received
760                elif self.serversock.fileno() == event[0]:
761                    self.logger.debug("Connection request received")
762                    self.readsock, _ = self.serversock.accept()
763                    self.readsock.setblocking(0)
764                    poll.unregister(self.serversock.fileno())
765                    poll.register(self.readsock.fileno(), event_read_mask)
766
767                    self.logger.debug("Setting connection established event")
768                    self.connection_established.set()
769
770                # Actual data to be logged
771                elif self.readsock.fileno() == event[0]:
772                    data = self.recv(1024)
773                    self.logfunc(data)
774
775    # Since the socket is non-blocking make sure to honor EAGAIN
776    # and EWOULDBLOCK.
777    def recv(self, count):
778        try:
779            data = self.readsock.recv(count)
780        except socket.error as e:
781            if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK:
782                return b''
783            else:
784                raise
785
786        if data is None:
787            raise Exception("No data on read ready socket")
788        elif not data:
789            # This actually means an orderly shutdown
790            # happened. But for this code it counts as an
791            # error since the connection shouldn't go away
792            # until qemu exits.
793            if not self.canexit:
794                raise Exception("Console connection closed unexpectedly")
795            return b''
796
797        return data
798
799    def stringify_event(self, event):
800        val = ''
801        if select.POLLERR == event:
802            val = 'POLLER'
803        elif select.POLLHUP == event:
804            val = 'POLLHUP'
805        elif select.POLLNVAL == event:
806            val = 'POLLNVAL'
807        return val
808
809    def close_socket(self, sock):
810        sock.shutdown(socket.SHUT_RDWR)
811        sock.close()
812
813    def close_ignore_error(self, fd):
814        try:
815            os.close(fd)
816        except OSError:
817            pass
818