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