blob: cda43aad8c5ecbe22347a9032ab874a9be1d292c [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
Andrew Geisslerc926e172021-05-07 16:11:35 -050022import tempfile
Andrew Geissler82c905d2020-04-13 13:39:40 -050023from collections import defaultdict
Patrick Williams169d7bc2024-01-05 11:33:25 -060024from contextlib import contextmanager
Andrew Geisslerc926e172021-05-07 16:11:35 -050025import importlib
Patrick Williams169d7bc2024-01-05 11:33:25 -060026import traceback
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 Williams169d7bc2024-01-05 11:33:25 -060034def getOutput(o):
35 import fcntl
36 fl = fcntl.fcntl(o, fcntl.F_GETFL)
37 fcntl.fcntl(o, fcntl.F_SETFL, fl | os.O_NONBLOCK)
38 try:
39 return os.read(o.fileno(), 1000000).decode("utf-8")
40 except BlockingIOError:
41 return ""
42
Patrick Williamsc124f4f2015-09-15 14:41:29 -050043class QemuRunner:
44
Andrew Geissler8f840682023-07-21 09:09:43 -050045 def __init__(self, machine, rootfs, display, tmpdir, deploy_dir_image, logfile, boottime, dump_dir, use_kvm, logger, use_slirp=False,
46 serial_ports=2, boot_patterns = defaultdict(str), use_ovmf=False, workdir=None, tmpfsdir=None):
Patrick Williamsc124f4f2015-09-15 14:41:29 -050047
48 # Popen object for runqemu
49 self.runqemu = None
Andrew Geissler82c905d2020-04-13 13:39:40 -050050 self.runqemu_exited = False
Patrick Williamsc124f4f2015-09-15 14:41:29 -050051 # pid of the qemu process that runqemu will start
52 self.qemupid = None
Brad Bishop6e60e8b2018-02-01 10:27:11 -050053 # target ip - from the command line or runqemu output
Patrick Williamsc124f4f2015-09-15 14:41:29 -050054 self.ip = None
55 # host ip - where qemu is running
56 self.server_ip = None
Brad Bishop6e60e8b2018-02-01 10:27:11 -050057 # target ip netmask
58 self.netmask = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -050059
60 self.machine = machine
61 self.rootfs = rootfs
62 self.display = display
63 self.tmpdir = tmpdir
64 self.deploy_dir_image = deploy_dir_image
65 self.logfile = logfile
66 self.boottime = boottime
67 self.logged = False
68 self.thread = None
Patrick Williams169d7bc2024-01-05 11:33:25 -060069 self.threadsock = None
Patrick Williamsc0f7c042017-02-23 20:41:17 -060070 self.use_kvm = use_kvm
Andrew Geissler82c905d2020-04-13 13:39:40 -050071 self.use_ovmf = use_ovmf
Brad Bishop19323692019-04-05 15:28:33 -040072 self.use_slirp = use_slirp
Andrew Geissler82c905d2020-04-13 13:39:40 -050073 self.serial_ports = serial_ports
Brad Bishopd7bf8c12018-02-25 22:55:05 -050074 self.msg = ''
Andrew Geissler82c905d2020-04-13 13:39:40 -050075 self.boot_patterns = boot_patterns
Andrew Geissler3b8a17c2021-04-15 15:55:55 -050076 self.tmpfsdir = tmpfsdir
Patrick Williamsc124f4f2015-09-15 14:41:29 -050077
Andrew Geissler09036742021-06-25 14:25:14 -050078 self.runqemutime = 300
Andrew Geisslerb7d28612020-07-24 16:15:54 -050079 if not workdir:
80 workdir = os.getcwd()
81 self.qemu_pidfile = workdir + '/pidfile_' + str(os.getpid())
Brad Bishop15ae2502019-06-18 21:44:24 -040082 self.monitorpipe = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -050083
Brad Bishopd7bf8c12018-02-25 22:55:05 -050084 self.logger = logger
William A. Kennington IIIac69b482021-06-02 12:28:27 -070085 # Whether we're expecting an exit and should show related errors
86 self.canexit = False
Brad Bishopd7bf8c12018-02-25 22:55:05 -050087
Andrew Geissler82c905d2020-04-13 13:39:40 -050088 # Enable testing other OS's
89 # Set commands for target communication, and default to Linux ALWAYS
90 # Other OS's or baremetal applications need to provide their
91 # own implementation passing it through QemuRunner's constructor
92 # or by passing them through TESTIMAGE_BOOT_PATTERNS[flag]
93 # provided variables, where <flag> is one of the mentioned below.
94 accepted_patterns = ['search_reached_prompt', 'send_login_user', 'search_login_succeeded', 'search_cmd_finished']
95 default_boot_patterns = defaultdict(str)
96 # Default to the usual paterns used to communicate with the target
Andrew Geissler87f5cff2022-09-30 13:13:31 -050097 default_boot_patterns['search_reached_prompt'] = ' login:'
Andrew Geissler82c905d2020-04-13 13:39:40 -050098 default_boot_patterns['send_login_user'] = 'root\n'
99 default_boot_patterns['search_login_succeeded'] = r"root@[a-zA-Z0-9\-]+:~#"
100 default_boot_patterns['search_cmd_finished'] = r"[a-zA-Z0-9]+@[a-zA-Z0-9\-]+:~#"
101
102 # Only override patterns that were set e.g. login user TESTIMAGE_BOOT_PATTERNS[send_login_user] = "webserver\n"
103 for pattern in accepted_patterns:
104 if not self.boot_patterns[pattern]:
105 self.boot_patterns[pattern] = default_boot_patterns[pattern]
106
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500107 def create_socket(self):
108 try:
109 sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
110 sock.setblocking(0)
Andrew Geissler20137392023-10-12 04:59:14 -0600111 sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500112 sock.bind(("127.0.0.1",0))
113 sock.listen(2)
114 port = sock.getsockname()[1]
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500115 self.logger.debug("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500116 return (sock, port)
117
118 except socket.error:
119 sock.close()
120 raise
121
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500122 def decode_qemulog(self, todecode):
123 # Sanitize the data received from qemu as it may contain control characters
Andrew Geissler20137392023-10-12 04:59:14 -0600124 msg = todecode.decode("utf-8", errors='backslashreplace')
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500125 msg = re_control_char.sub('', msg)
126 return msg
127
Andrew Geissler20137392023-10-12 04:59:14 -0600128 def log(self, msg, extension=""):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500129 if self.logfile:
Andrew Geissler20137392023-10-12 04:59:14 -0600130 with codecs.open(self.logfile + extension, "ab") as f:
131 f.write(msg)
132 self.msg += self.decode_qemulog(msg)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500133
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500134 def handleSIGCHLD(self, signum, frame):
135 if self.runqemu and self.runqemu.poll():
136 if self.runqemu.returncode:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500137 self.logger.error('runqemu exited with code %d' % self.runqemu.returncode)
Patrick Williams169d7bc2024-01-05 11:33:25 -0600138 self.logger.error('Output from runqemu:\n%s' % getOutput(self.runqemu.stdout))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500139 self.stop()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500140
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500141 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 -0500142 env = os.environ.copy()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500143 if self.display:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500144 env["DISPLAY"] = self.display
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500145 # Set this flag so that Qemu doesn't do any grabs as SDL grabs
146 # interact badly with screensavers.
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500147 env["QEMU_DONT_GRAB"] = "1"
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500148 if not os.path.exists(self.rootfs):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500149 self.logger.error("Invalid rootfs %s" % self.rootfs)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500150 return False
151 if not os.path.exists(self.tmpdir):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500152 self.logger.error("Invalid TMPDIR path %s" % self.tmpdir)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500153 return False
154 else:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500155 env["OE_TMPDIR"] = self.tmpdir
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500156 if not os.path.exists(self.deploy_dir_image):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500157 self.logger.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500158 return False
159 else:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500160 env["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500161
Andrew Geissler3b8a17c2021-04-15 15:55:55 -0500162 if self.tmpfsdir:
163 env["RUNQEMU_TMPFS_DIR"] = self.tmpfsdir
164
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500165 if not launch_cmd:
Brad Bishop08902b02019-08-20 09:16:51 -0400166 launch_cmd = 'runqemu %s' % ('snapshot' if discard_writes else '')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500167 if self.use_kvm:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500168 self.logger.debug('Using kvm for runqemu')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500169 launch_cmd += ' kvm'
170 else:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500171 self.logger.debug('Not using kvm for runqemu')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500172 if not self.display:
173 launch_cmd += ' nographic'
Brad Bishop19323692019-04-05 15:28:33 -0400174 if self.use_slirp:
175 launch_cmd += ' slirp'
Andrew Geissler82c905d2020-04-13 13:39:40 -0500176 if self.use_ovmf:
177 launch_cmd += ' ovmf'
Andrew Geissler517393d2023-01-13 08:55:19 -0600178 launch_cmd += ' %s %s' % (runqemuparams, self.machine)
179 if self.rootfs.endswith('.vmdk'):
180 self.logger.debug('Bypassing VMDK rootfs for runqemu')
181 else:
182 launch_cmd += ' %s' % (self.rootfs)
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500183
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500184 return self.launch(launch_cmd, qemuparams=qemuparams, get_ip=get_ip, extra_bootparams=extra_bootparams, env=env)
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500185
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500186 def launch(self, launch_cmd, get_ip = True, qemuparams = None, extra_bootparams = None, env = None):
Andrew Geisslerc926e172021-05-07 16:11:35 -0500187 # use logfile to determine the recipe-sysroot-native path and
188 # then add in the site-packages path components and add that
Patrick Williamsb542dec2023-06-09 01:26:37 -0500189 # to the python sys.path so the qmp module can be found.
Andrew Geisslerc926e172021-05-07 16:11:35 -0500190 python_path = os.path.dirname(os.path.dirname(self.logfile))
Andrew Geisslereff27472021-10-29 15:35:00 -0500191 python_path += "/recipe-sysroot-native/usr/lib/qemu-python"
Andrew Geisslerc926e172021-05-07 16:11:35 -0500192 sys.path.append(python_path)
193 importlib.invalidate_caches()
194 try:
195 qmp = importlib.import_module("qmp")
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500196 except Exception as e:
Patrick Williamsb542dec2023-06-09 01:26:37 -0500197 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 -0500198 return False
199 # Path relative to tmpdir used as cwd for qemu below to avoid unix socket path length issues
200 qmp_file = "." + next(tempfile._get_candidate_names())
201 qmp_param = ' -S -qmp unix:./%s,server,wait' % (qmp_file)
202 qmp_port = self.tmpdir + "/" + qmp_file
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600203 # Create a second socket connection for debugging use,
Andrew Geissler09036742021-06-25 14:25:14 -0500204 # note this will NOT cause qemu to block waiting for the connection
205 qmp_file2 = "." + next(tempfile._get_candidate_names())
206 qmp_param += ' -qmp unix:./%s,server,nowait' % (qmp_file2)
207 qmp_port2 = self.tmpdir + "/" + qmp_file2
208 self.logger.info("QMP Available for connection at %s" % (qmp_port2))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500209
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500210 try:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500211 if self.serial_ports >= 2:
212 self.threadsock, threadport = self.create_socket()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500213 self.server_socket, self.serverport = self.create_socket()
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600214 except socket.error as msg:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500215 self.logger.error("Failed to create listening socket: %s" % msg[1])
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500216 return False
217
Andrew Geissler95ac1b82021-03-31 14:34:31 -0500218 bootparams = ' printk.time=1'
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600219 if extra_bootparams:
220 bootparams = bootparams + ' ' + extra_bootparams
221
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500222 # Ask QEMU to store the QEMU process PID in file, this way we don't have to parse running processes
223 # and analyze descendents in order to determine it.
224 if os.path.exists(self.qemu_pidfile):
225 os.remove(self.qemu_pidfile)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500226 self.qemuparams = 'bootparams="{0}" qemuparams="-pidfile {1} {2}"'.format(bootparams, self.qemu_pidfile, qmp_param)
227
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500228 if qemuparams:
229 self.qemuparams = self.qemuparams[:-1] + " " + qemuparams + " " + '\"'
230
Andrew Geissler82c905d2020-04-13 13:39:40 -0500231 if self.serial_ports >= 2:
232 launch_cmd += ' tcpserial=%s:%s %s' % (threadport, self.serverport, self.qemuparams)
233 else:
234 launch_cmd += ' tcpserial=%s %s' % (self.serverport, self.qemuparams)
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500235
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500236 self.origchldhandler = signal.getsignal(signal.SIGCHLD)
237 signal.signal(signal.SIGCHLD, self.handleSIGCHLD)
238
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500239 self.logger.debug('launchcmd=%s' % (launch_cmd))
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600240
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500241 # FIXME: We pass in stdin=subprocess.PIPE here to work around stty
242 # blocking at the end of the runqemu script when using this within
243 # oe-selftest (this makes stty error out immediately). There ought
244 # to be a proper fix but this will suffice for now.
Andrew Geisslerc926e172021-05-07 16:11:35 -0500245 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 -0500246 output = self.runqemu.stdout
Andrew Geissler5f350902021-07-23 13:09:54 -0400247 launch_time = time.time()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500248
249 #
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600250 # We need the preexec_fn above so that all runqemu processes can easily be killed
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500251 # (by killing their process group). This presents a problem if this controlling
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600252 # process itself is killed however since those processes don't notice the death
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500253 # of the parent and merrily continue on.
254 #
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600255 # Rather than hack runqemu to deal with this, we add something here instead.
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500256 # Basically we fork off another process which holds an open pipe to the parent
257 # and also is setpgrp. If/when the pipe sees EOF from the parent dieing, it kills
258 # the process group. This is like pctrl's PDEATHSIG but for a process group
259 # rather than a single process.
260 #
261 r, w = os.pipe()
262 self.monitorpid = os.fork()
263 if self.monitorpid:
264 os.close(r)
265 self.monitorpipe = os.fdopen(w, "w")
266 else:
267 # child process
268 os.setpgrp()
269 os.close(w)
270 r = os.fdopen(r)
271 x = r.read()
272 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
Patrick Williams93c203f2021-10-06 16:15:23 -0500273 os._exit(0)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500274
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500275 self.logger.debug("runqemu started, pid is %s" % self.runqemu.pid)
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500276 self.logger.debug("waiting at most %d seconds for qemu pid (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400277 (self.runqemutime, time.strftime("%D %H:%M:%S")))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500278 endtime = time.time() + self.runqemutime
279 while not self.is_alive() and time.time() < endtime:
280 if self.runqemu.poll():
Andrew Geissler82c905d2020-04-13 13:39:40 -0500281 if self.runqemu_exited:
Andrew Geisslerc926e172021-05-07 16:11:35 -0500282 self.logger.warning("runqemu during is_alive() test")
Andrew Geissler82c905d2020-04-13 13:39:40 -0500283 return False
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500284 if self.runqemu.returncode:
285 # No point waiting any longer
Brad Bishop96ff1982019-08-19 13:50:42 -0400286 self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
Patrick Williams169d7bc2024-01-05 11:33:25 -0600287 self.logger.warning("Output from runqemu:\n%s" % getOutput(output))
Brad Bishopf86d0552018-12-04 14:18:15 -0800288 self.stop()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500289 return False
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500290 time.sleep(0.5)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500291
Andrew Geissler82c905d2020-04-13 13:39:40 -0500292 if self.runqemu_exited:
Andrew Geisslerc926e172021-05-07 16:11:35 -0500293 self.logger.warning("runqemu after timeout")
Andrew Geissler82c905d2020-04-13 13:39:40 -0500294
Andrew Geisslerc926e172021-05-07 16:11:35 -0500295 if self.runqemu.returncode:
296 self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500297
298 if not self.is_alive():
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500299 self.logger.error("Qemu pid didn't appear in %d seconds (%s)" %
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700300 (self.runqemutime, time.strftime("%D %H:%M:%S")))
301
302 qemu_pid = None
303 if os.path.isfile(self.qemu_pidfile):
304 with open(self.qemu_pidfile, 'r') as f:
305 qemu_pid = f.read().strip()
306
307 self.logger.error("Status information, poll status: %s, pidfile exists: %s, pidfile contents %s, proc pid exists %s"
308 % (self.runqemu.poll(), os.path.isfile(self.qemu_pidfile), str(qemu_pid), os.path.exists("/proc/" + str(qemu_pid))))
309
310 # Dump all processes to help us to figure out what is going on...
311 ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,pri,ni,command '], stdout=subprocess.PIPE).communicate()[0]
312 processes = ps.decode("utf-8")
313 self.logger.debug("Running processes:\n%s" % processes)
Patrick Williams169d7bc2024-01-05 11:33:25 -0600314 op = getOutput(output)
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700315 self.stop()
316 if op:
317 self.logger.error("Output from runqemu:\n%s" % op)
318 else:
319 self.logger.error("No output from runqemu.\n")
Andrew Geisslerc926e172021-05-07 16:11:35 -0500320 return False
321
322 # Create the client socket for the QEMU Monitor Control Socket
323 # This will allow us to read status from Qemu if the the process
324 # is still alive
325 self.logger.debug("QMP Initializing to %s" % (qmp_port))
326 # chdir dance for path length issues with unix sockets
327 origpath = os.getcwd()
328 try:
329 os.chdir(os.path.dirname(qmp_port))
330 try:
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500331 from qmp.legacy import QEMUMonitorProtocol
332 self.qmp = QEMUMonitorProtocol(os.path.basename(qmp_port))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500333 except OSError as msg:
334 self.logger.warning("Failed to initialize qemu monitor socket: %s File: %s" % (msg, msg.filename))
335 return False
336
337 self.logger.debug("QMP Connecting to %s" % (qmp_port))
338 if not os.path.exists(qmp_port) and self.is_alive():
339 self.logger.debug("QMP Port does not exist waiting for it to be created")
340 endtime = time.time() + self.runqemutime
341 while not os.path.exists(qmp_port) and self.is_alive() and time.time() < endtime:
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500342 self.logger.info("QMP port does not exist yet!")
343 time.sleep(0.5)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500344 if not os.path.exists(qmp_port) and self.is_alive():
345 self.logger.warning("QMP Port still does not exist but QEMU is alive")
346 return False
347
348 try:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600349 # set timeout value for all QMP calls
350 self.qmp.settimeout(self.runqemutime)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500351 self.qmp.connect()
Andrew Geissler5f350902021-07-23 13:09:54 -0400352 connect_time = time.time()
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500353 self.logger.info("QMP connected to QEMU at %s and took %.2f seconds" %
Andrew Geissler5f350902021-07-23 13:09:54 -0400354 (time.strftime("%D %H:%M:%S"),
355 time.time() - launch_time))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500356 except OSError as msg:
357 self.logger.warning("Failed to connect qemu monitor socket: %s File: %s" % (msg, msg.filename))
358 return False
Patrick Williams7784c422022-11-17 07:29:11 -0600359 except qmp.legacy.QMPError as msg:
Andrew Geisslerc926e172021-05-07 16:11:35 -0500360 self.logger.warning("Failed to communicate with qemu monitor: %s" % (msg))
361 return False
362 finally:
363 os.chdir(origpath)
364
Andrew Geissler09036742021-06-25 14:25:14 -0500365 # We worry that mmap'd libraries may cause page faults which hang the qemu VM for periods
366 # causing failures. Before we "start" qemu, read through it's mapped files to try and
367 # ensure we don't hit page faults later
368 mapdir = "/proc/" + str(self.qemupid) + "/map_files/"
369 try:
370 for f in os.listdir(mapdir):
Andrew Geissler5f350902021-07-23 13:09:54 -0400371 try:
372 linktarget = os.readlink(os.path.join(mapdir, f))
373 if not linktarget.startswith("/") or linktarget.startswith("/dev") or "deleted" in linktarget:
374 continue
375 with open(linktarget, "rb") as readf:
376 data = True
377 while data:
378 data = readf.read(4096)
379 except FileNotFoundError:
Andrew Geissler09036742021-06-25 14:25:14 -0500380 continue
Andrew Geissler09036742021-06-25 14:25:14 -0500381 # Centos7 doesn't allow us to read /map_files/
382 except PermissionError:
383 pass
384
385 # Release the qemu process to continue running
Andrew Geisslerc926e172021-05-07 16:11:35 -0500386 self.run_monitor('cont')
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500387 self.logger.info("QMP released QEMU at %s and took %.2f seconds from connect" %
Andrew Geissler5f350902021-07-23 13:09:54 -0400388 (time.strftime("%D %H:%M:%S"),
389 time.time() - connect_time))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500390
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500391 # We are alive: qemu is running
Patrick Williams169d7bc2024-01-05 11:33:25 -0600392 out = getOutput(output)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500393 netconf = False # network configuration is not required by default
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500394 self.logger.debug("qemu started in %.2f seconds - qemu procces pid is %s (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400395 (time.time() - (endtime - self.runqemutime),
396 self.qemupid, time.strftime("%D %H:%M:%S")))
Andrew Geissler82c905d2020-04-13 13:39:40 -0500397 cmdline = ''
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500398 if get_ip:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500399 with open('/proc/%s/cmdline' % self.qemupid) as p:
400 cmdline = p.read()
401 # It is needed to sanitize the data received
402 # because is possible to have control characters
403 cmdline = re_control_char.sub(' ', cmdline)
404 try:
Brad Bishop19323692019-04-05 15:28:33 -0400405 if self.use_slirp:
Andrew Geissler517393d2023-01-13 08:55:19 -0600406 tcp_ports = cmdline.split("hostfwd=tcp:")[1]
407 ip, tcp_ports = tcp_ports.split(":")[:2]
Brad Bishop19323692019-04-05 15:28:33 -0400408 host_port = tcp_ports[:tcp_ports.find('-')]
Andrew Geissler517393d2023-01-13 08:55:19 -0600409 self.ip = "%s:%s" % (ip, host_port)
Brad Bishop19323692019-04-05 15:28:33 -0400410 else:
411 ips = re.findall(r"((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1])
412 self.ip = ips[0]
413 self.server_ip = ips[1]
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500414 self.logger.debug("qemu cmdline used:\n{}".format(cmdline))
415 except (IndexError, ValueError):
416 # Try to get network configuration from runqemu output
Andrew Geissler595f6302022-01-24 19:11:47 +0000417 match = re.match(r'.*Network configuration: (?:ip=)*([0-9.]+)::([0-9.]+):([0-9.]+).*',
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500418 out, re.MULTILINE | re.DOTALL)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500419 if match:
420 self.ip, self.server_ip, self.netmask = match.groups()
421 # network configuration is required as we couldn't get it
422 # from the runqemu command line, so qemu doesn't run kernel
423 # and guest networking is not configured
424 netconf = True
425 else:
426 self.logger.error("Couldn't get ip from qemu command line and runqemu output! "
427 "Here is the qemu command line used:\n%s\n"
428 "and output from runqemu:\n%s" % (cmdline, out))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500429 self.stop()
430 return False
431
432 self.logger.debug("Target IP: %s" % self.ip)
433 self.logger.debug("Server IP: %s" % self.server_ip)
434
Patrick Williams169d7bc2024-01-05 11:33:25 -0600435 self.thread = LoggingThread(self.log, self.threadsock, self.logger, self.runqemu.stdout)
436 self.thread.start()
437
Andrew Geissler82c905d2020-04-13 13:39:40 -0500438 if self.serial_ports >= 2:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500439 if not self.thread.connection_established.wait(self.boottime):
440 self.logger.error("Didn't receive a console connection from qemu. "
441 "Here is the qemu command line used:\n%s\nand "
442 "output from runqemu:\n%s" % (cmdline, out))
443 self.stop_thread()
444 return False
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500445
446 self.logger.debug("Output from runqemu:\n%s", out)
Brad Bishop316dfdd2018-06-25 12:45:53 -0400447 self.logger.debug("Waiting at most %d seconds for login banner (%s)" %
448 (self.boottime, time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500449 endtime = time.time() + self.boottime
Patrick Williams169d7bc2024-01-05 11:33:25 -0600450 filelist = [self.server_socket]
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500451 reachedlogin = False
452 stopread = False
453 qemusock = None
454 bootlog = b''
455 data = b''
456 while time.time() < endtime and not stopread:
457 try:
Patrick Williamse760df82023-05-26 11:10:49 -0500458 sread, swrite, serror = select.select(filelist, [], [], 5)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500459 except InterruptedError:
460 continue
Patrick Williamse760df82023-05-26 11:10:49 -0500461 for file in sread:
462 if file is self.server_socket:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500463 qemusock, addr = self.server_socket.accept()
Patrick Williamse760df82023-05-26 11:10:49 -0500464 qemusock.setblocking(False)
465 filelist.append(qemusock)
466 filelist.remove(self.server_socket)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500467 self.logger.debug("Connection from %s:%s" % addr)
468 else:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600469 # try to avoid reading only a single character at a time
470 time.sleep(0.1)
Patrick Williamse760df82023-05-26 11:10:49 -0500471 if hasattr(file, 'read'):
472 read = file.read(1024)
473 elif hasattr(file, 'recv'):
474 read = file.recv(1024)
475 else:
476 self.logger.error('Invalid file type: %s\n%s' % (file))
477 read = b''
478
Andrew Geissler20137392023-10-12 04:59:14 -0600479 self.logger.debug2('Partial boot log:\n%s' % (read.decode('utf-8', errors='backslashreplace')))
Patrick Williamse760df82023-05-26 11:10:49 -0500480 data = data + read
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500481 if data:
482 bootlog += data
Andrew Geissler20137392023-10-12 04:59:14 -0600483 self.log(data, extension = ".2")
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500484 data = b''
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500485
Andrew Geissler20137392023-10-12 04:59:14 -0600486 if bytes(self.boot_patterns['search_reached_prompt'], 'utf-8') in bootlog:
Patrick Williamse760df82023-05-26 11:10:49 -0500487 self.server_socket.close()
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500488 self.server_socket = qemusock
489 stopread = True
490 reachedlogin = True
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500491 self.logger.debug("Reached login banner in %.2f seconds (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400492 (time.time() - (endtime - self.boottime),
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500493 time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500494 else:
Brad Bishop316dfdd2018-06-25 12:45:53 -0400495 # no need to check if reachedlogin unless we support multiple connections
496 self.logger.debug("QEMU socket disconnected before login banner reached. (%s)" %
497 time.strftime("%D %H:%M:%S"))
Patrick Williamse760df82023-05-26 11:10:49 -0500498 filelist.remove(file)
499 file.close()
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500500 stopread = True
501
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500502 if not reachedlogin:
Brad Bishop316dfdd2018-06-25 12:45:53 -0400503 if time.time() >= endtime:
Brad Bishop96ff1982019-08-19 13:50:42 -0400504 self.logger.warning("Target didn't reach login banner in %d seconds (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400505 (self.boottime, time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500506 tail = lambda l: "\n".join(l.splitlines()[-25:])
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500507 bootlog = self.decode_qemulog(bootlog)
Andrew Geissler20137392023-10-12 04:59:14 -0600508 self.logger.warning("Last 25 lines of login console (%d):\n%s" % (len(bootlog), tail(bootlog)))
509 self.logger.warning("Last 25 lines of all logging (%d):\n%s" % (len(self.msg), tail(self.msg)))
Brad Bishop96ff1982019-08-19 13:50:42 -0400510 self.logger.warning("Check full boot log: %s" % self.logfile)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500511 self.stop()
Andrew Geissler20137392023-10-12 04:59:14 -0600512 data = True
513 while data:
514 try:
515 time.sleep(1)
516 data = qemusock.recv(1024)
517 self.log(data, extension = ".2")
518 self.logger.warning('Extra log data read: %s\n' % (data.decode('utf-8', errors='backslashreplace')))
519 except Exception as e:
520 self.logger.warning('Extra log data exception %s' % repr(e))
521 data = None
Patrick Williams169d7bc2024-01-05 11:33:25 -0600522 self.thread.serial_lock.release()
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500523 return False
524
Patrick Williams169d7bc2024-01-05 11:33:25 -0600525 with self.thread.serial_lock:
526 self.thread.set_serialsock(self.server_socket)
527
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500528 # If we are not able to login the tests can continue
529 try:
Andrew Geisslerc3d88e42020-10-02 09:45:00 -0500530 (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120)
Andrew Geissler82c905d2020-04-13 13:39:40 -0500531 if re.search(self.boot_patterns['search_login_succeeded'], output):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500532 self.logged = True
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500533 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 -0500534 if netconf:
535 # configure guest networking
536 cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask)
537 output = self.run_serial(cmd, raw=True)[1]
Brad Bishopf86d0552018-12-04 14:18:15 -0800538 if re.search(r"root@[a-zA-Z0-9\-]+:~#", output):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500539 self.logger.debug("configured ip address %s", self.ip)
540 else:
541 self.logger.debug("Couldn't configure guest networking")
542 else:
Brad Bishop96ff1982019-08-19 13:50:42 -0400543 self.logger.warning("Couldn't login into serial console"
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500544 " as %s using blank password" % self.boot_patterns['send_login_user'].replace("\n", ""))
Brad Bishop96ff1982019-08-19 13:50:42 -0400545 self.logger.warning("The output:\n%s" % output)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500546 except:
Brad Bishop96ff1982019-08-19 13:50:42 -0400547 self.logger.warning("Serial console failed while trying to login")
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500548 return True
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500549
550 def stop(self):
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500551 if hasattr(self, "origchldhandler"):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500552 signal.signal(signal.SIGCHLD, self.origchldhandler)
Brad Bishop1a4b7ee2018-12-16 17:11:34 -0800553 self.stop_thread()
554 self.stop_qemu_system()
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500555 if self.runqemu:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600556 if hasattr(self, "monitorpid"):
557 os.kill(self.monitorpid, signal.SIGKILL)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500558 self.logger.debug("Sending SIGTERM to runqemu")
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600559 try:
560 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
561 except OSError as e:
562 if e.errno != errno.ESRCH:
563 raise
Patrick Williams864cc432023-02-09 14:54:44 -0600564 try:
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500565 outs, errs = self.runqemu.communicate(timeout=self.runqemutime)
Patrick Williams864cc432023-02-09 14:54:44 -0600566 if outs:
567 self.logger.info("Output from runqemu:\n%s", outs.decode("utf-8"))
568 if errs:
569 self.logger.info("Stderr from runqemu:\n%s", errs.decode("utf-8"))
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500570 except subprocess.TimeoutExpired:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500571 self.logger.debug("Sending SIGKILL to runqemu")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500572 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL)
Andrew Geisslerd159c7f2021-09-02 21:05:58 -0500573 if not self.runqemu.stdout.closed:
Patrick Williams169d7bc2024-01-05 11:33:25 -0600574 self.logger.info("Output from runqemu:\n%s" % getOutput(self.runqemu.stdout))
Brad Bishopf86d0552018-12-04 14:18:15 -0800575 self.runqemu.stdin.close()
576 self.runqemu.stdout.close()
Andrew Geissler82c905d2020-04-13 13:39:40 -0500577 self.runqemu_exited = True
Brad Bishopf86d0552018-12-04 14:18:15 -0800578
Andrew Geisslerc926e172021-05-07 16:11:35 -0500579 if hasattr(self, 'qmp') and self.qmp:
580 self.qmp.close()
581 self.qmp = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500582 if hasattr(self, 'server_socket') and self.server_socket:
583 self.server_socket.close()
584 self.server_socket = None
Brad Bishopf86d0552018-12-04 14:18:15 -0800585 if hasattr(self, 'threadsock') and self.threadsock:
586 self.threadsock.close()
587 self.threadsock = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500588 self.qemupid = None
589 self.ip = None
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500590 if os.path.exists(self.qemu_pidfile):
Andrew Geissler82c905d2020-04-13 13:39:40 -0500591 try:
592 os.remove(self.qemu_pidfile)
593 except FileNotFoundError as e:
594 # We raced, ignore
595 pass
Brad Bishopf86d0552018-12-04 14:18:15 -0800596 if self.monitorpipe:
597 self.monitorpipe.close()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500598
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500599 def stop_qemu_system(self):
600 if self.qemupid:
601 try:
602 # qemu-system behaves well and a SIGTERM is enough
603 os.kill(self.qemupid, signal.SIGTERM)
604 except ProcessLookupError as e:
Brad Bishop1a4b7ee2018-12-16 17:11:34 -0800605 self.logger.warning('qemu-system ended unexpectedly')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500606
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500607 def stop_thread(self):
608 if self.thread and self.thread.is_alive():
609 self.thread.stop()
610 self.thread.join()
611
Andrew Geisslerc926e172021-05-07 16:11:35 -0500612 def allowexit(self):
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700613 self.canexit = True
Andrew Geisslerc926e172021-05-07 16:11:35 -0500614 if self.thread:
615 self.thread.allowexit()
616
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500617 def restart(self, qemuparams = None):
Brad Bishop96ff1982019-08-19 13:50:42 -0400618 self.logger.warning("Restarting qemu process")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500619 if self.runqemu.poll() is None:
620 self.stop()
621 if self.start(qemuparams):
622 return True
623 return False
624
625 def is_alive(self):
Andrew Geissler82c905d2020-04-13 13:39:40 -0500626 if not self.runqemu or self.runqemu.poll() is not None or self.runqemu_exited:
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500627 return False
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500628 if os.path.isfile(self.qemu_pidfile):
Brad Bishop96ff1982019-08-19 13:50:42 -0400629 # when handling pidfile, qemu creates the file, stat it, lock it and then write to it
630 # so it's possible that the file has been created but the content is empty
631 pidfile_timeout = time.time() + 3
632 while time.time() < pidfile_timeout:
Patrick Williams73bd93f2024-02-20 08:07:48 -0600633 try:
634 with open(self.qemu_pidfile, 'r') as f:
635 qemu_pid = f.read().strip()
636 except FileNotFoundError:
637 # Can be used to detect shutdown so the pid file can disappear
638 return False
Brad Bishop96ff1982019-08-19 13:50:42 -0400639 # file created but not yet written contents
640 if not qemu_pid:
641 time.sleep(0.5)
642 continue
643 else:
644 if os.path.exists("/proc/" + qemu_pid):
645 self.qemupid = int(qemu_pid)
646 return True
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500647 return False
648
Andrew Geissler5f350902021-07-23 13:09:54 -0400649 def run_monitor(self, command, args=None, timeout=60):
650 if hasattr(self, 'qmp') and self.qmp:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600651 self.qmp.settimeout(timeout)
Andrew Geissler5f350902021-07-23 13:09:54 -0400652 if args is not None:
Patrick Williamsb58112e2024-03-07 11:16:36 -0600653 return self.qmp.cmd_raw(command, args)
Andrew Geissler5f350902021-07-23 13:09:54 -0400654 else:
Patrick Williamsb58112e2024-03-07 11:16:36 -0600655 return self.qmp.cmd_raw(command)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500656
Brad Bishop977dc1a2019-02-06 16:01:43 -0500657 def run_serial(self, command, raw=False, timeout=60):
Patrick Williams92b42cb2022-09-03 06:53:57 -0500658 # Returns (status, output) where status is 1 on success and 0 on error
659
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500660 # We assume target system have echo to get command status
661 if not raw:
662 command = "%s; echo $?\n" % command
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500663
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500664 data = ''
665 status = 0
Patrick Williams169d7bc2024-01-05 11:33:25 -0600666 with self.thread.serial_lock:
667 self.server_socket.sendall(command.encode('utf-8'))
668 start = time.time()
669 end = start + timeout
670 while True:
671 now = time.time()
672 if now >= end:
673 data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout
674 break
675 try:
676 sread, _, _ = select.select([self.server_socket],[],[], end - now)
677 except InterruptedError:
678 continue
679 if sread:
680 # try to avoid reading single character at a time
681 time.sleep(0.1)
682 answer = self.server_socket.recv(1024)
683 if answer:
684 data += answer.decode('utf-8')
685 # Search the prompt to stop
686 if re.search(self.boot_patterns['search_cmd_finished'], data):
687 break
688 else:
689 if self.canexit:
690 return (1, "")
691 raise Exception("No data on serial console socket, connection closed?")
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500692
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500693 if data:
694 if raw:
695 status = 1
696 else:
697 # Remove first line (command line) and last line (prompt)
698 data = data[data.find('$?\r\n')+4:data.rfind('\r\n')]
699 index = data.rfind('\r\n')
700 if index == -1:
701 status_cmd = data
702 data = ""
703 else:
704 status_cmd = data[index+2:]
705 data = data[:index]
706 if (status_cmd == "0"):
707 status = 1
708 return (status, str(data))
709
Patrick Williams169d7bc2024-01-05 11:33:25 -0600710@contextmanager
711def nonblocking_lock(lock):
712 locked = lock.acquire(False)
713 try:
714 yield locked
715 finally:
716 if locked:
717 lock.release()
718
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500719# This class is for reading data from a socket and passing it to logfunc
720# to be processed. It's completely event driven and has a straightforward
721# event loop. The mechanism for stopping the thread is a simple pipe which
722# will wake up the poll and allow for tearing everything down.
723class LoggingThread(threading.Thread):
Patrick Williams169d7bc2024-01-05 11:33:25 -0600724 def __init__(self, logfunc, sock, logger, qemuoutput):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500725 self.connection_established = threading.Event()
Patrick Williams169d7bc2024-01-05 11:33:25 -0600726 self.serial_lock = threading.Lock()
727
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500728 self.serversock = sock
Patrick Williams169d7bc2024-01-05 11:33:25 -0600729 self.serialsock = None
730 self.qemuoutput = qemuoutput
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500731 self.logfunc = logfunc
732 self.logger = logger
733 self.readsock = None
734 self.running = False
Andrew Geisslerc926e172021-05-07 16:11:35 -0500735 self.canexit = False
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500736
737 self.errorevents = select.POLLERR | select.POLLHUP | select.POLLNVAL
738 self.readevents = select.POLLIN | select.POLLPRI
739
740 threading.Thread.__init__(self, target=self.threadtarget)
741
Patrick Williams169d7bc2024-01-05 11:33:25 -0600742 def set_serialsock(self, serialsock):
743 self.serialsock = serialsock
744
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500745 def threadtarget(self):
746 try:
747 self.eventloop()
Patrick Williams169d7bc2024-01-05 11:33:25 -0600748 except Exception as e:
749 self.logger.warning("Exception %s in logging thread" % traceback.format_exception(e))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500750 finally:
751 self.teardown()
752
753 def run(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500754 self.logger.debug("Starting logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500755 self.readpipe, self.writepipe = os.pipe()
756 threading.Thread.run(self)
757
758 def stop(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500759 self.logger.debug("Stopping logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500760 if self.running:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600761 os.write(self.writepipe, bytes("stop", "utf-8"))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500762
763 def teardown(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500764 self.logger.debug("Tearing down logging thread")
Patrick Williams169d7bc2024-01-05 11:33:25 -0600765 if self.serversock:
766 self.close_socket(self.serversock)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500767
768 if self.readsock is not None:
769 self.close_socket(self.readsock)
770
771 self.close_ignore_error(self.readpipe)
772 self.close_ignore_error(self.writepipe)
773 self.running = False
774
Andrew Geisslerc926e172021-05-07 16:11:35 -0500775 def allowexit(self):
776 self.canexit = True
777
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500778 def eventloop(self):
779 poll = select.poll()
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500780 event_read_mask = self.errorevents | self.readevents
Patrick Williams169d7bc2024-01-05 11:33:25 -0600781 if self.serversock:
782 poll.register(self.serversock.fileno())
783 serial_registered = False
784 poll.register(self.qemuoutput.fileno())
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500785 poll.register(self.readpipe, event_read_mask)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500786
787 breakout = False
788 self.running = True
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500789 self.logger.debug("Starting thread event loop")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500790 while not breakout:
Patrick Williams169d7bc2024-01-05 11:33:25 -0600791 events = poll.poll(2)
792 for fd, event in events:
793
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500794 # An error occurred, bail out
Patrick Williams169d7bc2024-01-05 11:33:25 -0600795 if event & self.errorevents:
796 raise Exception(self.stringify_event(event))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500797
798 # Event to stop the thread
Patrick Williams169d7bc2024-01-05 11:33:25 -0600799 if self.readpipe == fd:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500800 self.logger.debug("Stop event received")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500801 breakout = True
802 break
803
804 # A connection request was received
Patrick Williams169d7bc2024-01-05 11:33:25 -0600805 elif self.serversock and self.serversock.fileno() == fd:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500806 self.logger.debug("Connection request received")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500807 self.readsock, _ = self.serversock.accept()
808 self.readsock.setblocking(0)
809 poll.unregister(self.serversock.fileno())
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500810 poll.register(self.readsock.fileno(), event_read_mask)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500811
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500812 self.logger.debug("Setting connection established event")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500813 self.connection_established.set()
814
815 # Actual data to be logged
Patrick Williams169d7bc2024-01-05 11:33:25 -0600816 elif self.readsock and self.readsock.fileno() == fd:
817 data = self.recv(1024, self.readsock)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500818 self.logfunc(data)
Patrick Williams169d7bc2024-01-05 11:33:25 -0600819 elif self.qemuoutput.fileno() == fd:
820 data = self.qemuoutput.read()
821 self.logger.debug("Data received on qemu stdout %s" % data)
822 self.logfunc(data, ".stdout")
823 elif self.serialsock and self.serialsock.fileno() == fd:
824 if self.serial_lock.acquire(blocking=False):
825 data = self.recv(1024, self.serialsock)
826 self.logger.debug("Data received serial thread %s" % data.decode('utf-8', 'replace'))
827 self.logfunc(data, ".2")
828 self.serial_lock.release()
829 else:
830 serial_registered = False
831 poll.unregister(self.serialsock.fileno())
832
833 if not serial_registered and self.serialsock:
834 with nonblocking_lock(self.serial_lock) as l:
835 if l:
836 serial_registered = True
837 poll.register(self.serialsock.fileno(), event_read_mask)
838
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500839
840 # Since the socket is non-blocking make sure to honor EAGAIN
841 # and EWOULDBLOCK.
Patrick Williams169d7bc2024-01-05 11:33:25 -0600842 def recv(self, count, sock):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500843 try:
Patrick Williams169d7bc2024-01-05 11:33:25 -0600844 data = sock.recv(count)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500845 except socket.error as e:
846 if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK:
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700847 return b''
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500848 else:
849 raise
850
851 if data is None:
852 raise Exception("No data on read ready socket")
853 elif not data:
854 # This actually means an orderly shutdown
855 # happened. But for this code it counts as an
856 # error since the connection shouldn't go away
857 # until qemu exits.
Andrew Geisslerc926e172021-05-07 16:11:35 -0500858 if not self.canexit:
859 raise Exception("Console connection closed unexpectedly")
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700860 return b''
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500861
862 return data
863
864 def stringify_event(self, event):
865 val = ''
866 if select.POLLERR == event:
867 val = 'POLLER'
868 elif select.POLLHUP == event:
869 val = 'POLLHUP'
870 elif select.POLLNVAL == event:
871 val = 'POLLNVAL'
Patrick Williams169d7bc2024-01-05 11:33:25 -0600872 else:
873 val = "0x%x" % (event)
874
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500875 return val
876
877 def close_socket(self, sock):
878 sock.shutdown(socket.SHUT_RDWR)
879 sock.close()
880
881 def close_ignore_error(self, fd):
882 try:
883 os.close(fd)
884 except OSError:
885 pass