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.bind(("127.0.0.1",0))
101            sock.listen(2)
102            port = sock.getsockname()[1]
103            self.logger.debug("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port)
104            return (sock, port)
105
106        except socket.error:
107            sock.close()
108            raise
109
110    def decode_qemulog(self, todecode):
111        # Sanitize the data received from qemu as it may contain control characters
112        msg = todecode.decode("utf-8", errors='ignore')
113        msg = re_control_char.sub('', msg)
114        return msg
115
116    def log(self, msg):
117        if self.logfile:
118            msg = self.decode_qemulog(msg)
119            self.msg += msg
120            with codecs.open(self.logfile, "a", encoding="utf-8") as f:
121                f.write("%s" % 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='ignore')))
478                    data = data + read
479                    if data:
480                        bootlog += data
481                        if self.serial_ports < 2:
482                            # this file has mixed console/kernel data, log it to logfile
483                            self.log(data)
484
485                        data = b''
486
487                        decodedlog = self.decode_qemulog(bootlog)
488                        if self.boot_patterns['search_reached_prompt'] in decodedlog:
489                            self.server_socket.close()
490                            self.server_socket = qemusock
491                            stopread = True
492                            reachedlogin = True
493                            self.logger.debug("Reached login banner in %.2f seconds (%s)" %
494                                              (time.time() - (endtime - self.boottime),
495                                              time.strftime("%D %H:%M:%S")))
496                    else:
497                        # no need to check if reachedlogin unless we support multiple connections
498                        self.logger.debug("QEMU socket disconnected before login banner reached. (%s)" %
499                                          time.strftime("%D %H:%M:%S"))
500                        filelist.remove(file)
501                        file.close()
502                        stopread = True
503
504        if not reachedlogin:
505            if time.time() >= endtime:
506                self.logger.warning("Target didn't reach login banner in %d seconds (%s)" %
507                                  (self.boottime, time.strftime("%D %H:%M:%S")))
508            tail = lambda l: "\n".join(l.splitlines()[-25:])
509            bootlog = self.decode_qemulog(bootlog)
510            # in case bootlog is empty, use tail qemu log store at self.msg
511            lines = tail(bootlog if bootlog else self.msg)
512            self.logger.warning("Last 25 lines of text (%d):\n%s" % (len(bootlog), lines))
513            self.logger.warning("Check full boot log: %s" % self.logfile)
514            self.stop()
515            return False
516
517        # If we are not able to login the tests can continue
518        try:
519            (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120)
520            if re.search(self.boot_patterns['search_login_succeeded'], output):
521                self.logged = True
522                self.logger.debug("Logged in as %s in serial console" % self.boot_patterns['send_login_user'].replace("\n", ""))
523                if netconf:
524                    # configure guest networking
525                    cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask)
526                    output = self.run_serial(cmd, raw=True)[1]
527                    if re.search(r"root@[a-zA-Z0-9\-]+:~#", output):
528                        self.logger.debug("configured ip address %s", self.ip)
529                    else:
530                        self.logger.debug("Couldn't configure guest networking")
531            else:
532                self.logger.warning("Couldn't login into serial console"
533                            " as %s using blank password" % self.boot_patterns['send_login_user'].replace("\n", ""))
534                self.logger.warning("The output:\n%s" % output)
535        except:
536            self.logger.warning("Serial console failed while trying to login")
537        return True
538
539    def stop(self):
540        if hasattr(self, "origchldhandler"):
541            signal.signal(signal.SIGCHLD, self.origchldhandler)
542        self.stop_thread()
543        self.stop_qemu_system()
544        if self.runqemu:
545            if hasattr(self, "monitorpid"):
546                os.kill(self.monitorpid, signal.SIGKILL)
547                self.logger.debug("Sending SIGTERM to runqemu")
548                try:
549                    os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
550                except OSError as e:
551                    if e.errno != errno.ESRCH:
552                        raise
553            try:
554                outs, errs = self.runqemu.communicate(timeout=self.runqemutime)
555                if outs:
556                    self.logger.info("Output from runqemu:\n%s", outs.decode("utf-8"))
557                if errs:
558                    self.logger.info("Stderr from runqemu:\n%s", errs.decode("utf-8"))
559            except subprocess.TimeoutExpired:
560                self.logger.debug("Sending SIGKILL to runqemu")
561                os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL)
562            if not self.runqemu.stdout.closed:
563                self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout))
564            self.runqemu.stdin.close()
565            self.runqemu.stdout.close()
566            self.runqemu_exited = True
567
568        if hasattr(self, 'qmp') and self.qmp:
569            self.qmp.close()
570            self.qmp = None
571        if hasattr(self, 'server_socket') and self.server_socket:
572            self.server_socket.close()
573            self.server_socket = None
574        if hasattr(self, 'threadsock') and self.threadsock:
575            self.threadsock.close()
576            self.threadsock = None
577        self.qemupid = None
578        self.ip = None
579        if os.path.exists(self.qemu_pidfile):
580            try:
581                os.remove(self.qemu_pidfile)
582            except FileNotFoundError as e:
583                # We raced, ignore
584                pass
585        if self.monitorpipe:
586            self.monitorpipe.close()
587
588    def stop_qemu_system(self):
589        if self.qemupid:
590            try:
591                # qemu-system behaves well and a SIGTERM is enough
592                os.kill(self.qemupid, signal.SIGTERM)
593            except ProcessLookupError as e:
594                self.logger.warning('qemu-system ended unexpectedly')
595
596    def stop_thread(self):
597        if self.thread and self.thread.is_alive():
598            self.thread.stop()
599            self.thread.join()
600
601    def allowexit(self):
602        self.canexit = True
603        if self.thread:
604            self.thread.allowexit()
605
606    def restart(self, qemuparams = None):
607        self.logger.warning("Restarting qemu process")
608        if self.runqemu.poll() is None:
609            self.stop()
610        if self.start(qemuparams):
611            return True
612        return False
613
614    def is_alive(self):
615        if not self.runqemu or self.runqemu.poll() is not None or self.runqemu_exited:
616            return False
617        if os.path.isfile(self.qemu_pidfile):
618            # when handling pidfile, qemu creates the file, stat it, lock it and then write to it
619            # so it's possible that the file has been created but the content is empty
620            pidfile_timeout = time.time() + 3
621            while time.time() < pidfile_timeout:
622                with open(self.qemu_pidfile, 'r') as f:
623                    qemu_pid = f.read().strip()
624                # file created but not yet written contents
625                if not qemu_pid:
626                    time.sleep(0.5)
627                    continue
628                else:
629                    if os.path.exists("/proc/" + qemu_pid):
630                        self.qemupid = int(qemu_pid)
631                        return True
632        return False
633
634    def run_monitor(self, command, args=None, timeout=60):
635        if hasattr(self, 'qmp') and self.qmp:
636            self.qmp.settimeout(timeout)
637            if args is not None:
638                return self.qmp.cmd(command, args)
639            else:
640                return self.qmp.cmd(command)
641
642    def run_serial(self, command, raw=False, timeout=60):
643        # Returns (status, output) where status is 1 on success and 0 on error
644
645        # We assume target system have echo to get command status
646        if not raw:
647            command = "%s; echo $?\n" % command
648
649        data = ''
650        status = 0
651        self.server_socket.sendall(command.encode('utf-8'))
652        start = time.time()
653        end = start + timeout
654        while True:
655            now = time.time()
656            if now >= end:
657                data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout
658                break
659            try:
660                sread, _, _ = select.select([self.server_socket],[],[], end - now)
661            except InterruptedError:
662                continue
663            if sread:
664                # try to avoid reading single character at a time
665                time.sleep(0.1)
666                answer = self.server_socket.recv(1024)
667                if answer:
668                    data += answer.decode('utf-8')
669                    # Search the prompt to stop
670                    if re.search(self.boot_patterns['search_cmd_finished'], data):
671                        break
672                else:
673                    if self.canexit:
674                        return (1, "")
675                    raise Exception("No data on serial console socket, connection closed?")
676
677        if data:
678            if raw:
679                status = 1
680            else:
681                # Remove first line (command line) and last line (prompt)
682                data = data[data.find('$?\r\n')+4:data.rfind('\r\n')]
683                index = data.rfind('\r\n')
684                if index == -1:
685                    status_cmd = data
686                    data = ""
687                else:
688                    status_cmd = data[index+2:]
689                    data = data[:index]
690                if (status_cmd == "0"):
691                    status = 1
692        return (status, str(data))
693
694# This class is for reading data from a socket and passing it to logfunc
695# to be processed. It's completely event driven and has a straightforward
696# event loop. The mechanism for stopping the thread is a simple pipe which
697# will wake up the poll and allow for tearing everything down.
698class LoggingThread(threading.Thread):
699    def __init__(self, logfunc, sock, logger):
700        self.connection_established = threading.Event()
701        self.serversock = sock
702        self.logfunc = logfunc
703        self.logger = logger
704        self.readsock = None
705        self.running = False
706        self.canexit = False
707
708        self.errorevents = select.POLLERR | select.POLLHUP | select.POLLNVAL
709        self.readevents = select.POLLIN | select.POLLPRI
710
711        threading.Thread.__init__(self, target=self.threadtarget)
712
713    def threadtarget(self):
714        try:
715            self.eventloop()
716        finally:
717            self.teardown()
718
719    def run(self):
720        self.logger.debug("Starting logging thread")
721        self.readpipe, self.writepipe = os.pipe()
722        threading.Thread.run(self)
723
724    def stop(self):
725        self.logger.debug("Stopping logging thread")
726        if self.running:
727            os.write(self.writepipe, bytes("stop", "utf-8"))
728
729    def teardown(self):
730        self.logger.debug("Tearing down logging thread")
731        self.close_socket(self.serversock)
732
733        if self.readsock is not None:
734            self.close_socket(self.readsock)
735
736        self.close_ignore_error(self.readpipe)
737        self.close_ignore_error(self.writepipe)
738        self.running = False
739
740    def allowexit(self):
741        self.canexit = True
742
743    def eventloop(self):
744        poll = select.poll()
745        event_read_mask = self.errorevents | self.readevents
746        poll.register(self.serversock.fileno())
747        poll.register(self.readpipe, event_read_mask)
748
749        breakout = False
750        self.running = True
751        self.logger.debug("Starting thread event loop")
752        while not breakout:
753            events = poll.poll()
754            for event in events:
755                # An error occurred, bail out
756                if event[1] & self.errorevents:
757                    raise Exception(self.stringify_event(event[1]))
758
759                # Event to stop the thread
760                if self.readpipe == event[0]:
761                    self.logger.debug("Stop event received")
762                    breakout = True
763                    break
764
765                # A connection request was received
766                elif self.serversock.fileno() == event[0]:
767                    self.logger.debug("Connection request received")
768                    self.readsock, _ = self.serversock.accept()
769                    self.readsock.setblocking(0)
770                    poll.unregister(self.serversock.fileno())
771                    poll.register(self.readsock.fileno(), event_read_mask)
772
773                    self.logger.debug("Setting connection established event")
774                    self.connection_established.set()
775
776                # Actual data to be logged
777                elif self.readsock.fileno() == event[0]:
778                    data = self.recv(1024)
779                    self.logfunc(data)
780
781    # Since the socket is non-blocking make sure to honor EAGAIN
782    # and EWOULDBLOCK.
783    def recv(self, count):
784        try:
785            data = self.readsock.recv(count)
786        except socket.error as e:
787            if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK:
788                return b''
789            else:
790                raise
791
792        if data is None:
793            raise Exception("No data on read ready socket")
794        elif not data:
795            # This actually means an orderly shutdown
796            # happened. But for this code it counts as an
797            # error since the connection shouldn't go away
798            # until qemu exits.
799            if not self.canexit:
800                raise Exception("Console connection closed unexpectedly")
801            return b''
802
803        return data
804
805    def stringify_event(self, event):
806        val = ''
807        if select.POLLERR == event:
808            val = 'POLLER'
809        elif select.POLLHUP == event:
810            val = 'POLLHUP'
811        elif select.POLLNVAL == event:
812            val = 'POLLNVAL'
813        return val
814
815    def close_socket(self, sock):
816        sock.shutdown(socket.SHUT_RDWR)
817        sock.close()
818
819    def close_ignore_error(self, fd):
820        try:
821            os.close(fd)
822        except OSError:
823            pass
824