blob: 0ef8cf0a792979d3641b3ecc9827e88b6b85a431 [file] [log] [blame]
Brad Bishopc342db32019-05-15 21:57:59 -04001#
Patrick Williamsc124f4f2015-09-15 14:41:29 -05002# Copyright (C) 2013 Intel Corporation
3#
Brad Bishopc342db32019-05-15 21:57:59 -04004# SPDX-License-Identifier: MIT
5#
Patrick Williamsc124f4f2015-09-15 14:41:29 -05006
7# This module provides a class for starting qemu images using runqemu.
8# It's used by testimage.bbclass.
9
10import subprocess
11import os
Brad Bishop6e60e8b2018-02-01 10:27:11 -050012import sys
Patrick Williamsc124f4f2015-09-15 14:41:29 -050013import time
14import signal
15import re
16import socket
17import select
18import errno
Patrick Williamsf1e5d692016-03-30 15:21:19 -050019import string
Patrick Williamsc124f4f2015-09-15 14:41:29 -050020import threading
Patrick Williamsf1e5d692016-03-30 15:21:19 -050021import codecs
Patrick Williamsc124f4f2015-09-15 14:41:29 -050022import logging
Andrew Geisslerc926e172021-05-07 16:11:35 -050023import tempfile
Brad Bishopd7bf8c12018-02-25 22:55:05 -050024from oeqa.utils.dump import HostDumper
Andrew Geissler82c905d2020-04-13 13:39:40 -050025from collections import defaultdict
Andrew Geisslerc926e172021-05-07 16:11:35 -050026import importlib
Patrick Williamsc124f4f2015-09-15 14:41:29 -050027
Patrick Williamsf1e5d692016-03-30 15:21:19 -050028# Get Unicode non printable control chars
Patrick Williamsc0f7c042017-02-23 20:41:17 -060029control_range = list(range(0,32))+list(range(127,160))
30control_chars = [chr(x) for x in control_range
31 if chr(x) not in string.printable]
Patrick Williamsf1e5d692016-03-30 15:21:19 -050032re_control_char = re.compile('[%s]' % re.escape("".join(control_chars)))
33
Patrick Williamsc124f4f2015-09-15 14:41:29 -050034class QemuRunner:
35
Brad Bishop19323692019-04-05 15:28:33 -040036 def __init__(self, machine, rootfs, display, tmpdir, deploy_dir_image, logfile, boottime, dump_dir, dump_host_cmds,
Andrew Geissler3b8a17c2021-04-15 15:55:55 -050037 use_kvm, logger, use_slirp=False, serial_ports=2, boot_patterns = defaultdict(str), use_ovmf=False, workdir=None, tmpfsdir=None):
Patrick Williamsc124f4f2015-09-15 14:41:29 -050038
39 # Popen object for runqemu
40 self.runqemu = None
Andrew Geissler82c905d2020-04-13 13:39:40 -050041 self.runqemu_exited = False
Patrick Williamsc124f4f2015-09-15 14:41:29 -050042 # pid of the qemu process that runqemu will start
43 self.qemupid = None
Brad Bishop6e60e8b2018-02-01 10:27:11 -050044 # target ip - from the command line or runqemu output
Patrick Williamsc124f4f2015-09-15 14:41:29 -050045 self.ip = None
46 # host ip - where qemu is running
47 self.server_ip = None
Brad Bishop6e60e8b2018-02-01 10:27:11 -050048 # target ip netmask
49 self.netmask = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -050050
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 Williamsc0f7c042017-02-23 20:41:17 -060060 self.use_kvm = use_kvm
Andrew Geissler82c905d2020-04-13 13:39:40 -050061 self.use_ovmf = use_ovmf
Brad Bishop19323692019-04-05 15:28:33 -040062 self.use_slirp = use_slirp
Andrew Geissler82c905d2020-04-13 13:39:40 -050063 self.serial_ports = serial_ports
Brad Bishopd7bf8c12018-02-25 22:55:05 -050064 self.msg = ''
Andrew Geissler82c905d2020-04-13 13:39:40 -050065 self.boot_patterns = boot_patterns
Andrew Geissler3b8a17c2021-04-15 15:55:55 -050066 self.tmpfsdir = tmpfsdir
Patrick Williamsc124f4f2015-09-15 14:41:29 -050067
Andrew Geissler09036742021-06-25 14:25:14 -050068 self.runqemutime = 300
Andrew Geisslerb7d28612020-07-24 16:15:54 -050069 if not workdir:
70 workdir = os.getcwd()
71 self.qemu_pidfile = workdir + '/pidfile_' + str(os.getpid())
Patrick Williamsc124f4f2015-09-15 14:41:29 -050072 self.host_dumper = HostDumper(dump_host_cmds, dump_dir)
Brad Bishop15ae2502019-06-18 21:44:24 -040073 self.monitorpipe = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -050074
Brad Bishopd7bf8c12018-02-25 22:55:05 -050075 self.logger = logger
William A. Kennington IIIac69b482021-06-02 12:28:27 -070076 # Whether we're expecting an exit and should show related errors
77 self.canexit = False
Brad Bishopd7bf8c12018-02-25 22:55:05 -050078
Andrew Geissler82c905d2020-04-13 13:39:40 -050079 # 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 Geissler87f5cff2022-09-30 13:13:31 -050088 default_boot_patterns['search_reached_prompt'] = ' login:'
Andrew Geissler82c905d2020-04-13 13:39:40 -050089 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 Williamsc124f4f2015-09-15 14:41:29 -050098 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 Bishopd7bf8c12018-02-25 22:55:05 -0500105 self.logger.debug("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500106 return (sock, port)
107
108 except socket.error:
109 sock.close()
110 raise
111
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500112 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 Williamsc124f4f2015-09-15 14:41:29 -0500118 def log(self, msg):
119 if self.logfile:
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500120 msg = self.decode_qemulog(msg)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500121 self.msg += msg
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500122 with codecs.open(self.logfile, "a", encoding="utf-8") as f:
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500123 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 Geisslerd159c7f2021-09-02 21:05:58 -0500129 try:
130 return os.read(o.fileno(), 1000000).decode("utf-8")
131 except BlockingIOError:
132 return ""
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500133
134
135 def handleSIGCHLD(self, signum, frame):
136 if self.runqemu and self.runqemu.poll():
137 if self.runqemu.returncode:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500138 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 Williamsc124f4f2015-09-15 14:41:29 -0500140 self.stop()
141 self._dump_host()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500142
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500143 def start(self, qemuparams = None, get_ip = True, extra_bootparams = None, runqemuparams='', launch_cmd=None, discard_writes=True):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500144 env = os.environ.copy()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500145 if self.display:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500146 env["DISPLAY"] = self.display
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500147 # Set this flag so that Qemu doesn't do any grabs as SDL grabs
148 # interact badly with screensavers.
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500149 env["QEMU_DONT_GRAB"] = "1"
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500150 if not os.path.exists(self.rootfs):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500151 self.logger.error("Invalid rootfs %s" % self.rootfs)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500152 return False
153 if not os.path.exists(self.tmpdir):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500154 self.logger.error("Invalid TMPDIR path %s" % self.tmpdir)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500155 return False
156 else:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500157 env["OE_TMPDIR"] = self.tmpdir
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500158 if not os.path.exists(self.deploy_dir_image):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500159 self.logger.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500160 return False
161 else:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500162 env["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500163
Andrew Geissler3b8a17c2021-04-15 15:55:55 -0500164 if self.tmpfsdir:
165 env["RUNQEMU_TMPFS_DIR"] = self.tmpfsdir
166
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500167 if not launch_cmd:
Brad Bishop08902b02019-08-20 09:16:51 -0400168 launch_cmd = 'runqemu %s' % ('snapshot' if discard_writes else '')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500169 if self.use_kvm:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500170 self.logger.debug('Using kvm for runqemu')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500171 launch_cmd += ' kvm'
172 else:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500173 self.logger.debug('Not using kvm for runqemu')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500174 if not self.display:
175 launch_cmd += ' nographic'
Brad Bishop19323692019-04-05 15:28:33 -0400176 if self.use_slirp:
177 launch_cmd += ' slirp'
Andrew Geissler82c905d2020-04-13 13:39:40 -0500178 if self.use_ovmf:
179 launch_cmd += ' ovmf'
Andrew Geissler517393d2023-01-13 08:55:19 -0600180 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 Bishop6e60e8b2018-02-01 10:27:11 -0500185
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500186 return self.launch(launch_cmd, qemuparams=qemuparams, get_ip=get_ip, extra_bootparams=extra_bootparams, env=env)
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500187
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500188 def launch(self, launch_cmd, get_ip = True, qemuparams = None, extra_bootparams = None, env = None):
Andrew Geisslerc926e172021-05-07 16:11:35 -0500189 # use logfile to determine the recipe-sysroot-native path and
190 # then add in the site-packages path components and add that
Patrick Williamsb542dec2023-06-09 01:26:37 -0500191 # to the python sys.path so the qmp module can be found.
Andrew Geisslerc926e172021-05-07 16:11:35 -0500192 python_path = os.path.dirname(os.path.dirname(self.logfile))
Andrew Geisslereff27472021-10-29 15:35:00 -0500193 python_path += "/recipe-sysroot-native/usr/lib/qemu-python"
Andrew Geisslerc926e172021-05-07 16:11:35 -0500194 sys.path.append(python_path)
195 importlib.invalidate_caches()
196 try:
197 qmp = importlib.import_module("qmp")
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500198 except Exception as e:
Patrick Williamsb542dec2023-06-09 01:26:37 -0500199 self.logger.error("qemurunner: qmp module missing, please ensure it's installed in %s (%s)" % (python_path, str(e)))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500200 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 Geissler6aa7eec2023-03-03 12:41:14 -0600205 # Create a second socket connection for debugging use,
Andrew Geissler09036742021-06-25 14:25:14 -0500206 # 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 Geisslerc926e172021-05-07 16:11:35 -0500211
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500212 try:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500213 if self.serial_ports >= 2:
214 self.threadsock, threadport = self.create_socket()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500215 self.server_socket, self.serverport = self.create_socket()
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600216 except socket.error as msg:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500217 self.logger.error("Failed to create listening socket: %s" % msg[1])
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500218 return False
219
Andrew Geissler95ac1b82021-03-31 14:34:31 -0500220 bootparams = ' printk.time=1'
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600221 if extra_bootparams:
222 bootparams = bootparams + ' ' + extra_bootparams
223
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500224 # 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 Geisslerc926e172021-05-07 16:11:35 -0500228 self.qemuparams = 'bootparams="{0}" qemuparams="-pidfile {1} {2}"'.format(bootparams, self.qemu_pidfile, qmp_param)
229
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500230 if qemuparams:
231 self.qemuparams = self.qemuparams[:-1] + " " + qemuparams + " " + '\"'
232
Andrew Geissler82c905d2020-04-13 13:39:40 -0500233 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 Bishop6e60e8b2018-02-01 10:27:11 -0500237
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500238 self.origchldhandler = signal.getsignal(signal.SIGCHLD)
239 signal.signal(signal.SIGCHLD, self.handleSIGCHLD)
240
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500241 self.logger.debug('launchcmd=%s' % (launch_cmd))
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600242
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500243 # 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 Geisslerc926e172021-05-07 16:11:35 -0500247 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 Williamsc124f4f2015-09-15 14:41:29 -0500248 output = self.runqemu.stdout
Andrew Geissler5f350902021-07-23 13:09:54 -0400249 launch_time = time.time()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500250
251 #
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600252 # We need the preexec_fn above so that all runqemu processes can easily be killed
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500253 # (by killing their process group). This presents a problem if this controlling
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600254 # process itself is killed however since those processes don't notice the death
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500255 # of the parent and merrily continue on.
256 #
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600257 # Rather than hack runqemu to deal with this, we add something here instead.
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500258 # 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 Williams93c203f2021-10-06 16:15:23 -0500275 os._exit(0)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500276
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500277 self.logger.debug("runqemu started, pid is %s" % self.runqemu.pid)
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500278 self.logger.debug("waiting at most %d seconds for qemu pid (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400279 (self.runqemutime, time.strftime("%D %H:%M:%S")))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500280 endtime = time.time() + self.runqemutime
281 while not self.is_alive() and time.time() < endtime:
282 if self.runqemu.poll():
Andrew Geissler82c905d2020-04-13 13:39:40 -0500283 if self.runqemu_exited:
Andrew Geisslerc926e172021-05-07 16:11:35 -0500284 self.logger.warning("runqemu during is_alive() test")
Andrew Geissler82c905d2020-04-13 13:39:40 -0500285 return False
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500286 if self.runqemu.returncode:
287 # No point waiting any longer
Brad Bishop96ff1982019-08-19 13:50:42 -0400288 self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500289 self._dump_host()
Brad Bishop96ff1982019-08-19 13:50:42 -0400290 self.logger.warning("Output from runqemu:\n%s" % self.getOutput(output))
Brad Bishopf86d0552018-12-04 14:18:15 -0800291 self.stop()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500292 return False
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500293 time.sleep(0.5)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500294
Andrew Geissler82c905d2020-04-13 13:39:40 -0500295 if self.runqemu_exited:
Andrew Geisslerc926e172021-05-07 16:11:35 -0500296 self.logger.warning("runqemu after timeout")
Andrew Geissler82c905d2020-04-13 13:39:40 -0500297
Andrew Geisslerc926e172021-05-07 16:11:35 -0500298 if self.runqemu.returncode:
299 self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500300
301 if not self.is_alive():
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500302 self.logger.error("Qemu pid didn't appear in %d seconds (%s)" %
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700303 (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 Geisslerc926e172021-05-07 16:11:35 -0500324 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:
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500335 from qmp.legacy import QEMUMonitorProtocol
336 self.qmp = QEMUMonitorProtocol(os.path.basename(qmp_port))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500337 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:
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500346 self.logger.info("QMP port does not exist yet!")
347 time.sleep(0.5)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500348 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 Geissler6aa7eec2023-03-03 12:41:14 -0600353 # set timeout value for all QMP calls
354 self.qmp.settimeout(self.runqemutime)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500355 self.qmp.connect()
Andrew Geissler5f350902021-07-23 13:09:54 -0400356 connect_time = time.time()
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500357 self.logger.info("QMP connected to QEMU at %s and took %.2f seconds" %
Andrew Geissler5f350902021-07-23 13:09:54 -0400358 (time.strftime("%D %H:%M:%S"),
359 time.time() - launch_time))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500360 except OSError as msg:
361 self.logger.warning("Failed to connect qemu monitor socket: %s File: %s" % (msg, msg.filename))
362 return False
Patrick Williams7784c422022-11-17 07:29:11 -0600363 except qmp.legacy.QMPError as msg:
Andrew Geisslerc926e172021-05-07 16:11:35 -0500364 self.logger.warning("Failed to communicate with qemu monitor: %s" % (msg))
365 return False
366 finally:
367 os.chdir(origpath)
368
Andrew Geissler09036742021-06-25 14:25:14 -0500369 # 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 Geissler5f350902021-07-23 13:09:54 -0400375 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 Geissler09036742021-06-25 14:25:14 -0500384 continue
Andrew Geissler09036742021-06-25 14:25:14 -0500385 # Centos7 doesn't allow us to read /map_files/
386 except PermissionError:
387 pass
388
389 # Release the qemu process to continue running
Andrew Geisslerc926e172021-05-07 16:11:35 -0500390 self.run_monitor('cont')
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500391 self.logger.info("QMP released QEMU at %s and took %.2f seconds from connect" %
Andrew Geissler5f350902021-07-23 13:09:54 -0400392 (time.strftime("%D %H:%M:%S"),
393 time.time() - connect_time))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500394
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500395 # We are alive: qemu is running
396 out = self.getOutput(output)
397 netconf = False # network configuration is not required by default
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500398 self.logger.debug("qemu started in %.2f seconds - qemu procces pid is %s (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400399 (time.time() - (endtime - self.runqemutime),
400 self.qemupid, time.strftime("%D %H:%M:%S")))
Andrew Geissler82c905d2020-04-13 13:39:40 -0500401 cmdline = ''
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500402 if get_ip:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500403 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 Bishop19323692019-04-05 15:28:33 -0400409 if self.use_slirp:
Andrew Geissler517393d2023-01-13 08:55:19 -0600410 tcp_ports = cmdline.split("hostfwd=tcp:")[1]
411 ip, tcp_ports = tcp_ports.split(":")[:2]
Brad Bishop19323692019-04-05 15:28:33 -0400412 host_port = tcp_ports[:tcp_ports.find('-')]
Andrew Geissler517393d2023-01-13 08:55:19 -0600413 self.ip = "%s:%s" % (ip, host_port)
Brad Bishop19323692019-04-05 15:28:33 -0400414 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 Bishopd7bf8c12018-02-25 22:55:05 -0500418 self.logger.debug("qemu cmdline used:\n{}".format(cmdline))
419 except (IndexError, ValueError):
420 # Try to get network configuration from runqemu output
Andrew Geissler595f6302022-01-24 19:11:47 +0000421 match = re.match(r'.*Network configuration: (?:ip=)*([0-9.]+)::([0-9.]+):([0-9.]+).*',
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500422 out, re.MULTILINE | re.DOTALL)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500423 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 Geissler82c905d2020-04-13 13:39:40 -0500440 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 Bishopd7bf8c12018-02-25 22:55:05 -0500449
450 self.logger.debug("Output from runqemu:\n%s", out)
Brad Bishop316dfdd2018-06-25 12:45:53 -0400451 self.logger.debug("Waiting at most %d seconds for login banner (%s)" %
452 (self.boottime, time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500453 endtime = time.time() + self.boottime
Patrick Williamse760df82023-05-26 11:10:49 -0500454 filelist = [self.server_socket, self.runqemu.stdout]
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500455 reachedlogin = False
456 stopread = False
457 qemusock = None
458 bootlog = b''
459 data = b''
460 while time.time() < endtime and not stopread:
461 try:
Patrick Williamse760df82023-05-26 11:10:49 -0500462 sread, swrite, serror = select.select(filelist, [], [], 5)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500463 except InterruptedError:
464 continue
Patrick Williamse760df82023-05-26 11:10:49 -0500465 for file in sread:
466 if file is self.server_socket:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500467 qemusock, addr = self.server_socket.accept()
Patrick Williamse760df82023-05-26 11:10:49 -0500468 qemusock.setblocking(False)
469 filelist.append(qemusock)
470 filelist.remove(self.server_socket)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500471 self.logger.debug("Connection from %s:%s" % addr)
472 else:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600473 # try to avoid reading only a single character at a time
474 time.sleep(0.1)
Patrick Williamse760df82023-05-26 11:10:49 -0500475 if hasattr(file, 'read'):
476 read = file.read(1024)
477 elif hasattr(file, 'recv'):
478 read = file.recv(1024)
479 else:
480 self.logger.error('Invalid file type: %s\n%s' % (file))
481 read = b''
482
483 self.logger.debug2('Partial boot log:\n%s' % (read.decode('utf-8', errors='ignore')))
484 data = data + read
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500485 if data:
486 bootlog += data
Andrew Geissler82c905d2020-04-13 13:39:40 -0500487 if self.serial_ports < 2:
Patrick Williamse760df82023-05-26 11:10:49 -0500488 # this file has mixed console/kernel data, log it to logfile
Andrew Geissler82c905d2020-04-13 13:39:40 -0500489 self.log(data)
490
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500491 data = b''
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500492
493 decodedlog = self.decode_qemulog(bootlog)
494 if self.boot_patterns['search_reached_prompt'] in decodedlog:
Patrick Williamse760df82023-05-26 11:10:49 -0500495 self.server_socket.close()
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500496 self.server_socket = qemusock
497 stopread = True
498 reachedlogin = True
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500499 self.logger.debug("Reached login banner in %.2f seconds (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400500 (time.time() - (endtime - self.boottime),
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500501 time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500502 else:
Brad Bishop316dfdd2018-06-25 12:45:53 -0400503 # no need to check if reachedlogin unless we support multiple connections
504 self.logger.debug("QEMU socket disconnected before login banner reached. (%s)" %
505 time.strftime("%D %H:%M:%S"))
Patrick Williamse760df82023-05-26 11:10:49 -0500506 filelist.remove(file)
507 file.close()
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500508 stopread = True
509
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500510 if not reachedlogin:
Brad Bishop316dfdd2018-06-25 12:45:53 -0400511 if time.time() >= endtime:
Brad Bishop96ff1982019-08-19 13:50:42 -0400512 self.logger.warning("Target didn't reach login banner in %d seconds (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400513 (self.boottime, time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500514 tail = lambda l: "\n".join(l.splitlines()[-25:])
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500515 bootlog = self.decode_qemulog(bootlog)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500516 # in case bootlog is empty, use tail qemu log store at self.msg
517 lines = tail(bootlog if bootlog else self.msg)
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500518 self.logger.warning("Last 25 lines of text (%d):\n%s" % (len(bootlog), lines))
Brad Bishop96ff1982019-08-19 13:50:42 -0400519 self.logger.warning("Check full boot log: %s" % self.logfile)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500520 self._dump_host()
521 self.stop()
522 return False
523
524 # If we are not able to login the tests can continue
525 try:
Andrew Geisslerc3d88e42020-10-02 09:45:00 -0500526 (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120)
Andrew Geissler82c905d2020-04-13 13:39:40 -0500527 if re.search(self.boot_patterns['search_login_succeeded'], output):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500528 self.logged = True
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500529 self.logger.debug("Logged in as %s in serial console" % self.boot_patterns['send_login_user'].replace("\n", ""))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500530 if netconf:
531 # configure guest networking
532 cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask)
533 output = self.run_serial(cmd, raw=True)[1]
Brad Bishopf86d0552018-12-04 14:18:15 -0800534 if re.search(r"root@[a-zA-Z0-9\-]+:~#", output):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500535 self.logger.debug("configured ip address %s", self.ip)
536 else:
537 self.logger.debug("Couldn't configure guest networking")
538 else:
Brad Bishop96ff1982019-08-19 13:50:42 -0400539 self.logger.warning("Couldn't login into serial console"
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500540 " as %s using blank password" % self.boot_patterns['send_login_user'].replace("\n", ""))
Brad Bishop96ff1982019-08-19 13:50:42 -0400541 self.logger.warning("The output:\n%s" % output)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500542 except:
Brad Bishop96ff1982019-08-19 13:50:42 -0400543 self.logger.warning("Serial console failed while trying to login")
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500544 return True
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500545
546 def stop(self):
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500547 if hasattr(self, "origchldhandler"):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500548 signal.signal(signal.SIGCHLD, self.origchldhandler)
Brad Bishop1a4b7ee2018-12-16 17:11:34 -0800549 self.stop_thread()
550 self.stop_qemu_system()
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500551 if self.runqemu:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600552 if hasattr(self, "monitorpid"):
553 os.kill(self.monitorpid, signal.SIGKILL)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500554 self.logger.debug("Sending SIGTERM to runqemu")
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600555 try:
556 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
557 except OSError as e:
558 if e.errno != errno.ESRCH:
559 raise
Patrick Williams864cc432023-02-09 14:54:44 -0600560 try:
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500561 outs, errs = self.runqemu.communicate(timeout=self.runqemutime)
Patrick Williams864cc432023-02-09 14:54:44 -0600562 if outs:
563 self.logger.info("Output from runqemu:\n%s", outs.decode("utf-8"))
564 if errs:
565 self.logger.info("Stderr from runqemu:\n%s", errs.decode("utf-8"))
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500566 except subprocess.TimeoutExpired:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500567 self.logger.debug("Sending SIGKILL to runqemu")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500568 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL)
Andrew Geisslerd159c7f2021-09-02 21:05:58 -0500569 if not self.runqemu.stdout.closed:
570 self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout))
Brad Bishopf86d0552018-12-04 14:18:15 -0800571 self.runqemu.stdin.close()
572 self.runqemu.stdout.close()
Andrew Geissler82c905d2020-04-13 13:39:40 -0500573 self.runqemu_exited = True
Brad Bishopf86d0552018-12-04 14:18:15 -0800574
Andrew Geisslerc926e172021-05-07 16:11:35 -0500575 if hasattr(self, 'qmp') and self.qmp:
576 self.qmp.close()
577 self.qmp = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500578 if hasattr(self, 'server_socket') and self.server_socket:
579 self.server_socket.close()
580 self.server_socket = None
Brad Bishopf86d0552018-12-04 14:18:15 -0800581 if hasattr(self, 'threadsock') and self.threadsock:
582 self.threadsock.close()
583 self.threadsock = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500584 self.qemupid = None
585 self.ip = None
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500586 if os.path.exists(self.qemu_pidfile):
Andrew Geissler82c905d2020-04-13 13:39:40 -0500587 try:
588 os.remove(self.qemu_pidfile)
589 except FileNotFoundError as e:
590 # We raced, ignore
591 pass
Brad Bishopf86d0552018-12-04 14:18:15 -0800592 if self.monitorpipe:
593 self.monitorpipe.close()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500594
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500595 def stop_qemu_system(self):
596 if self.qemupid:
597 try:
598 # qemu-system behaves well and a SIGTERM is enough
599 os.kill(self.qemupid, signal.SIGTERM)
600 except ProcessLookupError as e:
Brad Bishop1a4b7ee2018-12-16 17:11:34 -0800601 self.logger.warning('qemu-system ended unexpectedly')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500602
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500603 def stop_thread(self):
604 if self.thread and self.thread.is_alive():
605 self.thread.stop()
606 self.thread.join()
607
Andrew Geisslerc926e172021-05-07 16:11:35 -0500608 def allowexit(self):
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700609 self.canexit = True
Andrew Geisslerc926e172021-05-07 16:11:35 -0500610 if self.thread:
611 self.thread.allowexit()
612
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500613 def restart(self, qemuparams = None):
Brad Bishop96ff1982019-08-19 13:50:42 -0400614 self.logger.warning("Restarting qemu process")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500615 if self.runqemu.poll() is None:
616 self.stop()
617 if self.start(qemuparams):
618 return True
619 return False
620
621 def is_alive(self):
Andrew Geissler82c905d2020-04-13 13:39:40 -0500622 if not self.runqemu or self.runqemu.poll() is not None or self.runqemu_exited:
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500623 return False
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500624 if os.path.isfile(self.qemu_pidfile):
Brad Bishop96ff1982019-08-19 13:50:42 -0400625 # when handling pidfile, qemu creates the file, stat it, lock it and then write to it
626 # so it's possible that the file has been created but the content is empty
627 pidfile_timeout = time.time() + 3
628 while time.time() < pidfile_timeout:
629 with open(self.qemu_pidfile, 'r') as f:
630 qemu_pid = f.read().strip()
631 # file created but not yet written contents
632 if not qemu_pid:
633 time.sleep(0.5)
634 continue
635 else:
636 if os.path.exists("/proc/" + qemu_pid):
637 self.qemupid = int(qemu_pid)
638 return True
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500639 return False
640
Andrew Geissler5f350902021-07-23 13:09:54 -0400641 def run_monitor(self, command, args=None, timeout=60):
642 if hasattr(self, 'qmp') and self.qmp:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600643 self.qmp.settimeout(timeout)
Andrew Geissler5f350902021-07-23 13:09:54 -0400644 if args is not None:
645 return self.qmp.cmd(command, args)
646 else:
647 return self.qmp.cmd(command)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500648
Brad Bishop977dc1a2019-02-06 16:01:43 -0500649 def run_serial(self, command, raw=False, timeout=60):
Patrick Williams92b42cb2022-09-03 06:53:57 -0500650 # Returns (status, output) where status is 1 on success and 0 on error
651
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500652 # We assume target system have echo to get command status
653 if not raw:
654 command = "%s; echo $?\n" % command
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500655
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500656 data = ''
657 status = 0
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600658 self.server_socket.sendall(command.encode('utf-8'))
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500659 start = time.time()
660 end = start + timeout
661 while True:
662 now = time.time()
663 if now >= end:
664 data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout
665 break
666 try:
667 sread, _, _ = select.select([self.server_socket],[],[], end - now)
668 except InterruptedError:
669 continue
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500670 if sread:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600671 # try to avoid reading single character at a time
672 time.sleep(0.1)
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500673 answer = self.server_socket.recv(1024)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500674 if answer:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600675 data += answer.decode('utf-8')
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500676 # Search the prompt to stop
Andrew Geissler82c905d2020-04-13 13:39:40 -0500677 if re.search(self.boot_patterns['search_cmd_finished'], data):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500678 break
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500679 else:
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700680 if self.canexit:
681 return (1, "")
682 raise Exception("No data on serial console socket, connection closed?")
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500683
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500684 if data:
685 if raw:
686 status = 1
687 else:
688 # Remove first line (command line) and last line (prompt)
689 data = data[data.find('$?\r\n')+4:data.rfind('\r\n')]
690 index = data.rfind('\r\n')
691 if index == -1:
692 status_cmd = data
693 data = ""
694 else:
695 status_cmd = data[index+2:]
696 data = data[:index]
697 if (status_cmd == "0"):
698 status = 1
699 return (status, str(data))
700
701
702 def _dump_host(self):
703 self.host_dumper.create_dir("qemu")
Brad Bishop1a4b7ee2018-12-16 17:11:34 -0800704 self.logger.warning("Qemu ended unexpectedly, dump data from host"
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500705 " is in %s" % self.host_dumper.dump_dir)
706 self.host_dumper.dump_host()
707
708# This class is for reading data from a socket and passing it to logfunc
709# to be processed. It's completely event driven and has a straightforward
710# event loop. The mechanism for stopping the thread is a simple pipe which
711# will wake up the poll and allow for tearing everything down.
712class LoggingThread(threading.Thread):
713 def __init__(self, logfunc, sock, logger):
714 self.connection_established = threading.Event()
715 self.serversock = sock
716 self.logfunc = logfunc
717 self.logger = logger
718 self.readsock = None
719 self.running = False
Andrew Geisslerc926e172021-05-07 16:11:35 -0500720 self.canexit = False
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500721
722 self.errorevents = select.POLLERR | select.POLLHUP | select.POLLNVAL
723 self.readevents = select.POLLIN | select.POLLPRI
724
725 threading.Thread.__init__(self, target=self.threadtarget)
726
727 def threadtarget(self):
728 try:
729 self.eventloop()
730 finally:
731 self.teardown()
732
733 def run(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500734 self.logger.debug("Starting logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500735 self.readpipe, self.writepipe = os.pipe()
736 threading.Thread.run(self)
737
738 def stop(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500739 self.logger.debug("Stopping logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500740 if self.running:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600741 os.write(self.writepipe, bytes("stop", "utf-8"))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500742
743 def teardown(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500744 self.logger.debug("Tearing down logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500745 self.close_socket(self.serversock)
746
747 if self.readsock is not None:
748 self.close_socket(self.readsock)
749
750 self.close_ignore_error(self.readpipe)
751 self.close_ignore_error(self.writepipe)
752 self.running = False
753
Andrew Geisslerc926e172021-05-07 16:11:35 -0500754 def allowexit(self):
755 self.canexit = True
756
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500757 def eventloop(self):
758 poll = select.poll()
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500759 event_read_mask = self.errorevents | self.readevents
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500760 poll.register(self.serversock.fileno())
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500761 poll.register(self.readpipe, event_read_mask)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500762
763 breakout = False
764 self.running = True
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500765 self.logger.debug("Starting thread event loop")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500766 while not breakout:
767 events = poll.poll()
768 for event in events:
769 # An error occurred, bail out
770 if event[1] & self.errorevents:
771 raise Exception(self.stringify_event(event[1]))
772
773 # Event to stop the thread
774 if self.readpipe == event[0]:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500775 self.logger.debug("Stop event received")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500776 breakout = True
777 break
778
779 # A connection request was received
780 elif self.serversock.fileno() == event[0]:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500781 self.logger.debug("Connection request received")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500782 self.readsock, _ = self.serversock.accept()
783 self.readsock.setblocking(0)
784 poll.unregister(self.serversock.fileno())
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500785 poll.register(self.readsock.fileno(), event_read_mask)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500786
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500787 self.logger.debug("Setting connection established event")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500788 self.connection_established.set()
789
790 # Actual data to be logged
791 elif self.readsock.fileno() == event[0]:
792 data = self.recv(1024)
793 self.logfunc(data)
794
795 # Since the socket is non-blocking make sure to honor EAGAIN
796 # and EWOULDBLOCK.
797 def recv(self, count):
798 try:
799 data = self.readsock.recv(count)
800 except socket.error as e:
801 if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK:
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700802 return b''
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500803 else:
804 raise
805
806 if data is None:
807 raise Exception("No data on read ready socket")
808 elif not data:
809 # This actually means an orderly shutdown
810 # happened. But for this code it counts as an
811 # error since the connection shouldn't go away
812 # until qemu exits.
Andrew Geisslerc926e172021-05-07 16:11:35 -0500813 if not self.canexit:
814 raise Exception("Console connection closed unexpectedly")
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700815 return b''
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500816
817 return data
818
819 def stringify_event(self, event):
820 val = ''
821 if select.POLLERR == event:
822 val = 'POLLER'
823 elif select.POLLHUP == event:
824 val = 'POLLHUP'
825 elif select.POLLNVAL == event:
826 val = 'POLLNVAL'
827 return val
828
829 def close_socket(self, sock):
830 sock.shutdown(socket.SHUT_RDWR)
831 sock.close()
832
833 def close_ignore_error(self, fd):
834 try:
835 os.close(fd)
836 except OSError:
837 pass