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