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 the qmp module 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 module missing, please ensure it's installed in %s (%s)" % (python_path, 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 %d 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 %d 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                # set timeout value for all QMP calls
354                self.qmp.settimeout(self.runqemutime)
355                self.qmp.connect()
356                connect_time = time.time()
357                self.logger.info("QMP connected to QEMU at %s and took %.2f seconds" %
358                                  (time.strftime("%D %H:%M:%S"),
359                                   time.time() - launch_time))
360            except OSError as msg:
361                self.logger.warning("Failed to connect qemu monitor socket: %s File: %s" % (msg, msg.filename))
362                return False
363            except qmp.legacy.QMPError as msg:
364                self.logger.warning("Failed to communicate with qemu monitor: %s" % (msg))
365                return False
366        finally:
367            os.chdir(origpath)
368
369        # We worry that mmap'd libraries may cause page faults which hang the qemu VM for periods
370        # causing failures. Before we "start" qemu, read through it's mapped files to try and
371        # ensure we don't hit page faults later
372        mapdir = "/proc/" + str(self.qemupid) + "/map_files/"
373        try:
374            for f in os.listdir(mapdir):
375                try:
376                    linktarget = os.readlink(os.path.join(mapdir, f))
377                    if not linktarget.startswith("/") or linktarget.startswith("/dev") or "deleted" in linktarget:
378                        continue
379                    with open(linktarget, "rb") as readf:
380                        data = True
381                        while data:
382                            data = readf.read(4096)
383                except FileNotFoundError:
384                    continue
385        # Centos7 doesn't allow us to read /map_files/
386        except PermissionError:
387            pass
388
389        # Release the qemu process to continue running
390        self.run_monitor('cont')
391        self.logger.info("QMP released QEMU at %s and took %.2f seconds from connect" %
392                          (time.strftime("%D %H:%M:%S"),
393                           time.time() - connect_time))
394
395        # We are alive: qemu is running
396        out = self.getOutput(output)
397        netconf = False # network configuration is not required by default
398        self.logger.debug("qemu started in %.2f seconds - qemu procces pid is %s (%s)" %
399                          (time.time() - (endtime - self.runqemutime),
400                           self.qemupid, time.strftime("%D %H:%M:%S")))
401        cmdline = ''
402        if get_ip:
403            with open('/proc/%s/cmdline' % self.qemupid) as p:
404                cmdline = p.read()
405                # It is needed to sanitize the data received
406                # because is possible to have control characters
407                cmdline = re_control_char.sub(' ', cmdline)
408            try:
409                if self.use_slirp:
410                    tcp_ports = cmdline.split("hostfwd=tcp:")[1]
411                    ip, tcp_ports = tcp_ports.split(":")[:2]
412                    host_port = tcp_ports[:tcp_ports.find('-')]
413                    self.ip = "%s:%s" % (ip, host_port)
414                else:
415                    ips = re.findall(r"((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1])
416                    self.ip = ips[0]
417                    self.server_ip = ips[1]
418                self.logger.debug("qemu cmdline used:\n{}".format(cmdline))
419            except (IndexError, ValueError):
420                # Try to get network configuration from runqemu output
421                match = re.match(r'.*Network configuration: (?:ip=)*([0-9.]+)::([0-9.]+):([0-9.]+).*',
422                                 out, re.MULTILINE | re.DOTALL)
423                if match:
424                    self.ip, self.server_ip, self.netmask = match.groups()
425                    # network configuration is required as we couldn't get it
426                    # from the runqemu command line, so qemu doesn't run kernel
427                    # and guest networking is not configured
428                    netconf = True
429                else:
430                    self.logger.error("Couldn't get ip from qemu command line and runqemu output! "
431                                 "Here is the qemu command line used:\n%s\n"
432                                 "and output from runqemu:\n%s" % (cmdline, out))
433                    self._dump_host()
434                    self.stop()
435                    return False
436
437        self.logger.debug("Target IP: %s" % self.ip)
438        self.logger.debug("Server IP: %s" % self.server_ip)
439
440        if self.serial_ports >= 2:
441            self.thread = LoggingThread(self.log, self.threadsock, self.logger)
442            self.thread.start()
443            if not self.thread.connection_established.wait(self.boottime):
444                self.logger.error("Didn't receive a console connection from qemu. "
445                             "Here is the qemu command line used:\n%s\nand "
446                             "output from runqemu:\n%s" % (cmdline, out))
447                self.stop_thread()
448                return False
449
450        self.logger.debug("Output from runqemu:\n%s", out)
451        self.logger.debug("Waiting at most %d seconds for login banner (%s)" %
452                          (self.boottime, time.strftime("%D %H:%M:%S")))
453        endtime = time.time() + self.boottime
454        filelist = [self.server_socket, self.runqemu.stdout]
455        reachedlogin = False
456        stopread = False
457        qemusock = None
458        bootlog = b''
459        data = b''
460        while time.time() < endtime and not stopread:
461            try:
462                sread, swrite, serror = select.select(filelist, [], [], 5)
463            except InterruptedError:
464                continue
465            for file in sread:
466                if file is self.server_socket:
467                    qemusock, addr = self.server_socket.accept()
468                    qemusock.setblocking(False)
469                    filelist.append(qemusock)
470                    filelist.remove(self.server_socket)
471                    self.logger.debug("Connection from %s:%s" % addr)
472                else:
473                    # try to avoid reading only a single character at a time
474                    time.sleep(0.1)
475                    if hasattr(file, 'read'):
476                        read = file.read(1024)
477                    elif hasattr(file, 'recv'):
478                        read = file.recv(1024)
479                    else:
480                        self.logger.error('Invalid file type: %s\n%s' % (file))
481                        read = b''
482
483                    self.logger.debug2('Partial boot log:\n%s' % (read.decode('utf-8', errors='ignore')))
484                    data = data + read
485                    if data:
486                        bootlog += data
487                        if self.serial_ports < 2:
488                            # this file has mixed console/kernel data, log it to logfile
489                            self.log(data)
490
491                        data = b''
492
493                        decodedlog = self.decode_qemulog(bootlog)
494                        if self.boot_patterns['search_reached_prompt'] in decodedlog:
495                            self.server_socket.close()
496                            self.server_socket = qemusock
497                            stopread = True
498                            reachedlogin = True
499                            self.logger.debug("Reached login banner in %.2f seconds (%s)" %
500                                              (time.time() - (endtime - self.boottime),
501                                              time.strftime("%D %H:%M:%S")))
502                    else:
503                        # no need to check if reachedlogin unless we support multiple connections
504                        self.logger.debug("QEMU socket disconnected before login banner reached. (%s)" %
505                                          time.strftime("%D %H:%M:%S"))
506                        filelist.remove(file)
507                        file.close()
508                        stopread = True
509
510        if not reachedlogin:
511            if time.time() >= endtime:
512                self.logger.warning("Target didn't reach login banner in %d seconds (%s)" %
513                                  (self.boottime, time.strftime("%D %H:%M:%S")))
514            tail = lambda l: "\n".join(l.splitlines()[-25:])
515            bootlog = self.decode_qemulog(bootlog)
516            # in case bootlog is empty, use tail qemu log store at self.msg
517            lines = tail(bootlog if bootlog else self.msg)
518            self.logger.warning("Last 25 lines of text (%d):\n%s" % (len(bootlog), lines))
519            self.logger.warning("Check full boot log: %s" % self.logfile)
520            self._dump_host()
521            self.stop()
522            return False
523
524        # If we are not able to login the tests can continue
525        try:
526            (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120)
527            if re.search(self.boot_patterns['search_login_succeeded'], output):
528                self.logged = True
529                self.logger.debug("Logged in as %s in serial console" % self.boot_patterns['send_login_user'].replace("\n", ""))
530                if netconf:
531                    # configure guest networking
532                    cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask)
533                    output = self.run_serial(cmd, raw=True)[1]
534                    if re.search(r"root@[a-zA-Z0-9\-]+:~#", output):
535                        self.logger.debug("configured ip address %s", self.ip)
536                    else:
537                        self.logger.debug("Couldn't configure guest networking")
538            else:
539                self.logger.warning("Couldn't login into serial console"
540                            " as %s using blank password" % self.boot_patterns['send_login_user'].replace("\n", ""))
541                self.logger.warning("The output:\n%s" % output)
542        except:
543            self.logger.warning("Serial console failed while trying to login")
544        return True
545
546    def stop(self):
547        if hasattr(self, "origchldhandler"):
548            signal.signal(signal.SIGCHLD, self.origchldhandler)
549        self.stop_thread()
550        self.stop_qemu_system()
551        if self.runqemu:
552            if hasattr(self, "monitorpid"):
553                os.kill(self.monitorpid, signal.SIGKILL)
554                self.logger.debug("Sending SIGTERM to runqemu")
555                try:
556                    os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
557                except OSError as e:
558                    if e.errno != errno.ESRCH:
559                        raise
560            try:
561                outs, errs = self.runqemu.communicate(timeout=self.runqemutime)
562                if outs:
563                    self.logger.info("Output from runqemu:\n%s", outs.decode("utf-8"))
564                if errs:
565                    self.logger.info("Stderr from runqemu:\n%s", errs.decode("utf-8"))
566            except subprocess.TimeoutExpired:
567                self.logger.debug("Sending SIGKILL to runqemu")
568                os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL)
569            if not self.runqemu.stdout.closed:
570                self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout))
571            self.runqemu.stdin.close()
572            self.runqemu.stdout.close()
573            self.runqemu_exited = True
574
575        if hasattr(self, 'qmp') and self.qmp:
576            self.qmp.close()
577            self.qmp = None
578        if hasattr(self, 'server_socket') and self.server_socket:
579            self.server_socket.close()
580            self.server_socket = None
581        if hasattr(self, 'threadsock') and self.threadsock:
582            self.threadsock.close()
583            self.threadsock = None
584        self.qemupid = None
585        self.ip = None
586        if os.path.exists(self.qemu_pidfile):
587            try:
588                os.remove(self.qemu_pidfile)
589            except FileNotFoundError as e:
590                # We raced, ignore
591                pass
592        if self.monitorpipe:
593            self.monitorpipe.close()
594
595    def stop_qemu_system(self):
596        if self.qemupid:
597            try:
598                # qemu-system behaves well and a SIGTERM is enough
599                os.kill(self.qemupid, signal.SIGTERM)
600            except ProcessLookupError as e:
601                self.logger.warning('qemu-system ended unexpectedly')
602
603    def stop_thread(self):
604        if self.thread and self.thread.is_alive():
605            self.thread.stop()
606            self.thread.join()
607
608    def allowexit(self):
609        self.canexit = True
610        if self.thread:
611            self.thread.allowexit()
612
613    def restart(self, qemuparams = None):
614        self.logger.warning("Restarting qemu process")
615        if self.runqemu.poll() is None:
616            self.stop()
617        if self.start(qemuparams):
618            return True
619        return False
620
621    def is_alive(self):
622        if not self.runqemu or self.runqemu.poll() is not None or self.runqemu_exited:
623            return False
624        if os.path.isfile(self.qemu_pidfile):
625            # when handling pidfile, qemu creates the file, stat it, lock it and then write to it
626            # so it's possible that the file has been created but the content is empty
627            pidfile_timeout = time.time() + 3
628            while time.time() < pidfile_timeout:
629                with open(self.qemu_pidfile, 'r') as f:
630                    qemu_pid = f.read().strip()
631                # file created but not yet written contents
632                if not qemu_pid:
633                    time.sleep(0.5)
634                    continue
635                else:
636                    if os.path.exists("/proc/" + qemu_pid):
637                        self.qemupid = int(qemu_pid)
638                        return True
639        return False
640
641    def run_monitor(self, command, args=None, timeout=60):
642        if hasattr(self, 'qmp') and self.qmp:
643            self.qmp.settimeout(timeout)
644            if args is not None:
645                return self.qmp.cmd(command, args)
646            else:
647                return self.qmp.cmd(command)
648
649    def run_serial(self, command, raw=False, timeout=60):
650        # Returns (status, output) where status is 1 on success and 0 on error
651
652        # We assume target system have echo to get command status
653        if not raw:
654            command = "%s; echo $?\n" % command
655
656        data = ''
657        status = 0
658        self.server_socket.sendall(command.encode('utf-8'))
659        start = time.time()
660        end = start + timeout
661        while True:
662            now = time.time()
663            if now >= end:
664                data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout
665                break
666            try:
667                sread, _, _ = select.select([self.server_socket],[],[], end - now)
668            except InterruptedError:
669                continue
670            if sread:
671                # try to avoid reading single character at a time
672                time.sleep(0.1)
673                answer = self.server_socket.recv(1024)
674                if answer:
675                    data += answer.decode('utf-8')
676                    # Search the prompt to stop
677                    if re.search(self.boot_patterns['search_cmd_finished'], data):
678                        break
679                else:
680                    if self.canexit:
681                        return (1, "")
682                    raise Exception("No data on serial console socket, connection closed?")
683
684        if data:
685            if raw:
686                status = 1
687            else:
688                # Remove first line (command line) and last line (prompt)
689                data = data[data.find('$?\r\n')+4:data.rfind('\r\n')]
690                index = data.rfind('\r\n')
691                if index == -1:
692                    status_cmd = data
693                    data = ""
694                else:
695                    status_cmd = data[index+2:]
696                    data = data[:index]
697                if (status_cmd == "0"):
698                    status = 1
699        return (status, str(data))
700
701
702    def _dump_host(self):
703        self.host_dumper.create_dir("qemu")
704        self.logger.warning("Qemu ended unexpectedly, dump data from host"
705                " is in %s" % self.host_dumper.dump_dir)
706        self.host_dumper.dump_host()
707
708# This class is for reading data from a socket and passing it to logfunc
709# to be processed. It's completely event driven and has a straightforward
710# event loop. The mechanism for stopping the thread is a simple pipe which
711# will wake up the poll and allow for tearing everything down.
712class LoggingThread(threading.Thread):
713    def __init__(self, logfunc, sock, logger):
714        self.connection_established = threading.Event()
715        self.serversock = sock
716        self.logfunc = logfunc
717        self.logger = logger
718        self.readsock = None
719        self.running = False
720        self.canexit = False
721
722        self.errorevents = select.POLLERR | select.POLLHUP | select.POLLNVAL
723        self.readevents = select.POLLIN | select.POLLPRI
724
725        threading.Thread.__init__(self, target=self.threadtarget)
726
727    def threadtarget(self):
728        try:
729            self.eventloop()
730        finally:
731            self.teardown()
732
733    def run(self):
734        self.logger.debug("Starting logging thread")
735        self.readpipe, self.writepipe = os.pipe()
736        threading.Thread.run(self)
737
738    def stop(self):
739        self.logger.debug("Stopping logging thread")
740        if self.running:
741            os.write(self.writepipe, bytes("stop", "utf-8"))
742
743    def teardown(self):
744        self.logger.debug("Tearing down logging thread")
745        self.close_socket(self.serversock)
746
747        if self.readsock is not None:
748            self.close_socket(self.readsock)
749
750        self.close_ignore_error(self.readpipe)
751        self.close_ignore_error(self.writepipe)
752        self.running = False
753
754    def allowexit(self):
755        self.canexit = True
756
757    def eventloop(self):
758        poll = select.poll()
759        event_read_mask = self.errorevents | self.readevents
760        poll.register(self.serversock.fileno())
761        poll.register(self.readpipe, event_read_mask)
762
763        breakout = False
764        self.running = True
765        self.logger.debug("Starting thread event loop")
766        while not breakout:
767            events = poll.poll()
768            for event in events:
769                # An error occurred, bail out
770                if event[1] & self.errorevents:
771                    raise Exception(self.stringify_event(event[1]))
772
773                # Event to stop the thread
774                if self.readpipe == event[0]:
775                    self.logger.debug("Stop event received")
776                    breakout = True
777                    break
778
779                # A connection request was received
780                elif self.serversock.fileno() == event[0]:
781                    self.logger.debug("Connection request received")
782                    self.readsock, _ = self.serversock.accept()
783                    self.readsock.setblocking(0)
784                    poll.unregister(self.serversock.fileno())
785                    poll.register(self.readsock.fileno(), event_read_mask)
786
787                    self.logger.debug("Setting connection established event")
788                    self.connection_established.set()
789
790                # Actual data to be logged
791                elif self.readsock.fileno() == event[0]:
792                    data = self.recv(1024)
793                    self.logfunc(data)
794
795    # Since the socket is non-blocking make sure to honor EAGAIN
796    # and EWOULDBLOCK.
797    def recv(self, count):
798        try:
799            data = self.readsock.recv(count)
800        except socket.error as e:
801            if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK:
802                return b''
803            else:
804                raise
805
806        if data is None:
807            raise Exception("No data on read ready socket")
808        elif not data:
809            # This actually means an orderly shutdown
810            # happened. But for this code it counts as an
811            # error since the connection shouldn't go away
812            # until qemu exits.
813            if not self.canexit:
814                raise Exception("Console connection closed unexpectedly")
815            return b''
816
817        return data
818
819    def stringify_event(self, event):
820        val = ''
821        if select.POLLERR == event:
822            val = 'POLLER'
823        elif select.POLLHUP == event:
824            val = 'POLLHUP'
825        elif select.POLLNVAL == event:
826            val = 'POLLNVAL'
827        return val
828
829    def close_socket(self, sock):
830        sock.shutdown(socket.SHUT_RDWR)
831        sock.close()
832
833    def close_ignore_error(self, fd):
834        try:
835            os.close(fd)
836        except OSError:
837            pass
838