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