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