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