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