blob: 29fe27197621770e7a34747776d322f887060ed2 [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
Andrew Geissler82c905d2020-04-13 13:39:40 -050024from collections import defaultdict
Andrew Geisslerc926e172021-05-07 16:11:35 -050025import importlib
Patrick Williamsc124f4f2015-09-15 14:41:29 -050026
Patrick Williamsf1e5d692016-03-30 15:21:19 -050027# Get Unicode non printable control chars
Patrick Williamsc0f7c042017-02-23 20:41:17 -060028control_range = list(range(0,32))+list(range(127,160))
29control_chars = [chr(x) for x in control_range
30 if chr(x) not in string.printable]
Patrick Williamsf1e5d692016-03-30 15:21:19 -050031re_control_char = re.compile('[%s]' % re.escape("".join(control_chars)))
32
Patrick Williamsc124f4f2015-09-15 14:41:29 -050033class QemuRunner:
34
Andrew Geissler8f840682023-07-21 09:09:43 -050035 def __init__(self, machine, rootfs, display, tmpdir, deploy_dir_image, logfile, boottime, dump_dir, use_kvm, logger, use_slirp=False,
36 serial_ports=2, boot_patterns = defaultdict(str), use_ovmf=False, workdir=None, tmpfsdir=None):
Patrick Williamsc124f4f2015-09-15 14:41:29 -050037
38 # Popen object for runqemu
39 self.runqemu = None
Andrew Geissler82c905d2020-04-13 13:39:40 -050040 self.runqemu_exited = False
Patrick Williamsc124f4f2015-09-15 14:41:29 -050041 # pid of the qemu process that runqemu will start
42 self.qemupid = None
Brad Bishop6e60e8b2018-02-01 10:27:11 -050043 # target ip - from the command line or runqemu output
Patrick Williamsc124f4f2015-09-15 14:41:29 -050044 self.ip = None
45 # host ip - where qemu is running
46 self.server_ip = None
Brad Bishop6e60e8b2018-02-01 10:27:11 -050047 # target ip netmask
48 self.netmask = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -050049
50 self.machine = machine
51 self.rootfs = rootfs
52 self.display = display
53 self.tmpdir = tmpdir
54 self.deploy_dir_image = deploy_dir_image
55 self.logfile = logfile
56 self.boottime = boottime
57 self.logged = False
58 self.thread = None
Patrick Williamsc0f7c042017-02-23 20:41:17 -060059 self.use_kvm = use_kvm
Andrew Geissler82c905d2020-04-13 13:39:40 -050060 self.use_ovmf = use_ovmf
Brad Bishop19323692019-04-05 15:28:33 -040061 self.use_slirp = use_slirp
Andrew Geissler82c905d2020-04-13 13:39:40 -050062 self.serial_ports = serial_ports
Brad Bishopd7bf8c12018-02-25 22:55:05 -050063 self.msg = ''
Andrew Geissler82c905d2020-04-13 13:39:40 -050064 self.boot_patterns = boot_patterns
Andrew Geissler3b8a17c2021-04-15 15:55:55 -050065 self.tmpfsdir = tmpfsdir
Patrick Williamsc124f4f2015-09-15 14:41:29 -050066
Andrew Geissler09036742021-06-25 14:25:14 -050067 self.runqemutime = 300
Andrew Geisslerb7d28612020-07-24 16:15:54 -050068 if not workdir:
69 workdir = os.getcwd()
70 self.qemu_pidfile = workdir + '/pidfile_' + str(os.getpid())
Brad Bishop15ae2502019-06-18 21:44:24 -040071 self.monitorpipe = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -050072
Brad Bishopd7bf8c12018-02-25 22:55:05 -050073 self.logger = logger
William A. Kennington IIIac69b482021-06-02 12:28:27 -070074 # Whether we're expecting an exit and should show related errors
75 self.canexit = False
Brad Bishopd7bf8c12018-02-25 22:55:05 -050076
Andrew Geissler82c905d2020-04-13 13:39:40 -050077 # Enable testing other OS's
78 # Set commands for target communication, and default to Linux ALWAYS
79 # Other OS's or baremetal applications need to provide their
80 # own implementation passing it through QemuRunner's constructor
81 # or by passing them through TESTIMAGE_BOOT_PATTERNS[flag]
82 # provided variables, where <flag> is one of the mentioned below.
83 accepted_patterns = ['search_reached_prompt', 'send_login_user', 'search_login_succeeded', 'search_cmd_finished']
84 default_boot_patterns = defaultdict(str)
85 # Default to the usual paterns used to communicate with the target
Andrew Geissler87f5cff2022-09-30 13:13:31 -050086 default_boot_patterns['search_reached_prompt'] = ' login:'
Andrew Geissler82c905d2020-04-13 13:39:40 -050087 default_boot_patterns['send_login_user'] = 'root\n'
88 default_boot_patterns['search_login_succeeded'] = r"root@[a-zA-Z0-9\-]+:~#"
89 default_boot_patterns['search_cmd_finished'] = r"[a-zA-Z0-9]+@[a-zA-Z0-9\-]+:~#"
90
91 # Only override patterns that were set e.g. login user TESTIMAGE_BOOT_PATTERNS[send_login_user] = "webserver\n"
92 for pattern in accepted_patterns:
93 if not self.boot_patterns[pattern]:
94 self.boot_patterns[pattern] = default_boot_patterns[pattern]
95
Patrick Williamsc124f4f2015-09-15 14:41:29 -050096 def create_socket(self):
97 try:
98 sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
99 sock.setblocking(0)
Andrew Geissler20137392023-10-12 04:59:14 -0600100 sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500101 sock.bind(("127.0.0.1",0))
102 sock.listen(2)
103 port = sock.getsockname()[1]
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500104 self.logger.debug("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500105 return (sock, port)
106
107 except socket.error:
108 sock.close()
109 raise
110
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500111 def decode_qemulog(self, todecode):
112 # Sanitize the data received from qemu as it may contain control characters
Andrew Geissler20137392023-10-12 04:59:14 -0600113 msg = todecode.decode("utf-8", errors='backslashreplace')
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500114 msg = re_control_char.sub('', msg)
115 return msg
116
Andrew Geissler20137392023-10-12 04:59:14 -0600117 def log(self, msg, extension=""):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500118 if self.logfile:
Andrew Geissler20137392023-10-12 04:59:14 -0600119 with codecs.open(self.logfile + extension, "ab") as f:
120 f.write(msg)
121 self.msg += self.decode_qemulog(msg)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500122
123 def getOutput(self, o):
124 import fcntl
125 fl = fcntl.fcntl(o, fcntl.F_GETFL)
126 fcntl.fcntl(o, fcntl.F_SETFL, fl | os.O_NONBLOCK)
Andrew Geisslerd159c7f2021-09-02 21:05:58 -0500127 try:
128 return os.read(o.fileno(), 1000000).decode("utf-8")
129 except BlockingIOError:
130 return ""
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500131
132
133 def handleSIGCHLD(self, signum, frame):
134 if self.runqemu and self.runqemu.poll():
135 if self.runqemu.returncode:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500136 self.logger.error('runqemu exited with code %d' % self.runqemu.returncode)
137 self.logger.error('Output from runqemu:\n%s' % self.getOutput(self.runqemu.stdout))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500138 self.stop()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500139
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500140 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 -0500141 env = os.environ.copy()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500142 if self.display:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500143 env["DISPLAY"] = self.display
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500144 # Set this flag so that Qemu doesn't do any grabs as SDL grabs
145 # interact badly with screensavers.
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500146 env["QEMU_DONT_GRAB"] = "1"
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500147 if not os.path.exists(self.rootfs):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500148 self.logger.error("Invalid rootfs %s" % self.rootfs)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500149 return False
150 if not os.path.exists(self.tmpdir):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500151 self.logger.error("Invalid TMPDIR path %s" % self.tmpdir)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500152 return False
153 else:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500154 env["OE_TMPDIR"] = self.tmpdir
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500155 if not os.path.exists(self.deploy_dir_image):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500156 self.logger.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500157 return False
158 else:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500159 env["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500160
Andrew Geissler3b8a17c2021-04-15 15:55:55 -0500161 if self.tmpfsdir:
162 env["RUNQEMU_TMPFS_DIR"] = self.tmpfsdir
163
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500164 if not launch_cmd:
Brad Bishop08902b02019-08-20 09:16:51 -0400165 launch_cmd = 'runqemu %s' % ('snapshot' if discard_writes else '')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500166 if self.use_kvm:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500167 self.logger.debug('Using kvm for runqemu')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500168 launch_cmd += ' kvm'
169 else:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500170 self.logger.debug('Not using kvm for runqemu')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500171 if not self.display:
172 launch_cmd += ' nographic'
Brad Bishop19323692019-04-05 15:28:33 -0400173 if self.use_slirp:
174 launch_cmd += ' slirp'
Andrew Geissler82c905d2020-04-13 13:39:40 -0500175 if self.use_ovmf:
176 launch_cmd += ' ovmf'
Andrew Geissler517393d2023-01-13 08:55:19 -0600177 launch_cmd += ' %s %s' % (runqemuparams, self.machine)
178 if self.rootfs.endswith('.vmdk'):
179 self.logger.debug('Bypassing VMDK rootfs for runqemu')
180 else:
181 launch_cmd += ' %s' % (self.rootfs)
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500182
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500183 return self.launch(launch_cmd, qemuparams=qemuparams, get_ip=get_ip, extra_bootparams=extra_bootparams, env=env)
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500184
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500185 def launch(self, launch_cmd, get_ip = True, qemuparams = None, extra_bootparams = None, env = None):
Andrew Geisslerc926e172021-05-07 16:11:35 -0500186 # use logfile to determine the recipe-sysroot-native path and
187 # then add in the site-packages path components and add that
Patrick Williamsb542dec2023-06-09 01:26:37 -0500188 # to the python sys.path so the qmp module can be found.
Andrew Geisslerc926e172021-05-07 16:11:35 -0500189 python_path = os.path.dirname(os.path.dirname(self.logfile))
Andrew Geisslereff27472021-10-29 15:35:00 -0500190 python_path += "/recipe-sysroot-native/usr/lib/qemu-python"
Andrew Geisslerc926e172021-05-07 16:11:35 -0500191 sys.path.append(python_path)
192 importlib.invalidate_caches()
193 try:
194 qmp = importlib.import_module("qmp")
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500195 except Exception as e:
Patrick Williamsb542dec2023-06-09 01:26:37 -0500196 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 -0500197 return False
198 # Path relative to tmpdir used as cwd for qemu below to avoid unix socket path length issues
199 qmp_file = "." + next(tempfile._get_candidate_names())
200 qmp_param = ' -S -qmp unix:./%s,server,wait' % (qmp_file)
201 qmp_port = self.tmpdir + "/" + qmp_file
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600202 # Create a second socket connection for debugging use,
Andrew Geissler09036742021-06-25 14:25:14 -0500203 # note this will NOT cause qemu to block waiting for the connection
204 qmp_file2 = "." + next(tempfile._get_candidate_names())
205 qmp_param += ' -qmp unix:./%s,server,nowait' % (qmp_file2)
206 qmp_port2 = self.tmpdir + "/" + qmp_file2
207 self.logger.info("QMP Available for connection at %s" % (qmp_port2))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500208
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500209 try:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500210 if self.serial_ports >= 2:
211 self.threadsock, threadport = self.create_socket()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500212 self.server_socket, self.serverport = self.create_socket()
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600213 except socket.error as msg:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500214 self.logger.error("Failed to create listening socket: %s" % msg[1])
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500215 return False
216
Andrew Geissler95ac1b82021-03-31 14:34:31 -0500217 bootparams = ' printk.time=1'
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600218 if extra_bootparams:
219 bootparams = bootparams + ' ' + extra_bootparams
220
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500221 # Ask QEMU to store the QEMU process PID in file, this way we don't have to parse running processes
222 # and analyze descendents in order to determine it.
223 if os.path.exists(self.qemu_pidfile):
224 os.remove(self.qemu_pidfile)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500225 self.qemuparams = 'bootparams="{0}" qemuparams="-pidfile {1} {2}"'.format(bootparams, self.qemu_pidfile, qmp_param)
226
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500227 if qemuparams:
228 self.qemuparams = self.qemuparams[:-1] + " " + qemuparams + " " + '\"'
229
Andrew Geissler82c905d2020-04-13 13:39:40 -0500230 if self.serial_ports >= 2:
231 launch_cmd += ' tcpserial=%s:%s %s' % (threadport, self.serverport, self.qemuparams)
232 else:
233 launch_cmd += ' tcpserial=%s %s' % (self.serverport, self.qemuparams)
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500234
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500235 self.origchldhandler = signal.getsignal(signal.SIGCHLD)
236 signal.signal(signal.SIGCHLD, self.handleSIGCHLD)
237
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500238 self.logger.debug('launchcmd=%s' % (launch_cmd))
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600239
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500240 # FIXME: We pass in stdin=subprocess.PIPE here to work around stty
241 # blocking at the end of the runqemu script when using this within
242 # oe-selftest (this makes stty error out immediately). There ought
243 # to be a proper fix but this will suffice for now.
Andrew Geisslerc926e172021-05-07 16:11:35 -0500244 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 -0500245 output = self.runqemu.stdout
Andrew Geissler5f350902021-07-23 13:09:54 -0400246 launch_time = time.time()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500247
248 #
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600249 # We need the preexec_fn above so that all runqemu processes can easily be killed
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500250 # (by killing their process group). This presents a problem if this controlling
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600251 # process itself is killed however since those processes don't notice the death
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500252 # of the parent and merrily continue on.
253 #
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600254 # Rather than hack runqemu to deal with this, we add something here instead.
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500255 # Basically we fork off another process which holds an open pipe to the parent
256 # and also is setpgrp. If/when the pipe sees EOF from the parent dieing, it kills
257 # the process group. This is like pctrl's PDEATHSIG but for a process group
258 # rather than a single process.
259 #
260 r, w = os.pipe()
261 self.monitorpid = os.fork()
262 if self.monitorpid:
263 os.close(r)
264 self.monitorpipe = os.fdopen(w, "w")
265 else:
266 # child process
267 os.setpgrp()
268 os.close(w)
269 r = os.fdopen(r)
270 x = r.read()
271 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
Patrick Williams93c203f2021-10-06 16:15:23 -0500272 os._exit(0)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500273
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500274 self.logger.debug("runqemu started, pid is %s" % self.runqemu.pid)
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500275 self.logger.debug("waiting at most %d seconds for qemu pid (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400276 (self.runqemutime, time.strftime("%D %H:%M:%S")))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500277 endtime = time.time() + self.runqemutime
278 while not self.is_alive() and time.time() < endtime:
279 if self.runqemu.poll():
Andrew Geissler82c905d2020-04-13 13:39:40 -0500280 if self.runqemu_exited:
Andrew Geisslerc926e172021-05-07 16:11:35 -0500281 self.logger.warning("runqemu during is_alive() test")
Andrew Geissler82c905d2020-04-13 13:39:40 -0500282 return False
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500283 if self.runqemu.returncode:
284 # No point waiting any longer
Brad Bishop96ff1982019-08-19 13:50:42 -0400285 self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
Brad Bishop96ff1982019-08-19 13:50:42 -0400286 self.logger.warning("Output from runqemu:\n%s" % self.getOutput(output))
Brad Bishopf86d0552018-12-04 14:18:15 -0800287 self.stop()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500288 return False
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500289 time.sleep(0.5)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500290
Andrew Geissler82c905d2020-04-13 13:39:40 -0500291 if self.runqemu_exited:
Andrew Geisslerc926e172021-05-07 16:11:35 -0500292 self.logger.warning("runqemu after timeout")
Andrew Geissler82c905d2020-04-13 13:39:40 -0500293
Andrew Geisslerc926e172021-05-07 16:11:35 -0500294 if self.runqemu.returncode:
295 self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500296
297 if not self.is_alive():
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500298 self.logger.error("Qemu pid didn't appear in %d seconds (%s)" %
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700299 (self.runqemutime, time.strftime("%D %H:%M:%S")))
300
301 qemu_pid = None
302 if os.path.isfile(self.qemu_pidfile):
303 with open(self.qemu_pidfile, 'r') as f:
304 qemu_pid = f.read().strip()
305
306 self.logger.error("Status information, poll status: %s, pidfile exists: %s, pidfile contents %s, proc pid exists %s"
307 % (self.runqemu.poll(), os.path.isfile(self.qemu_pidfile), str(qemu_pid), os.path.exists("/proc/" + str(qemu_pid))))
308
309 # Dump all processes to help us to figure out what is going on...
310 ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,pri,ni,command '], stdout=subprocess.PIPE).communicate()[0]
311 processes = ps.decode("utf-8")
312 self.logger.debug("Running processes:\n%s" % processes)
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700313 op = self.getOutput(output)
314 self.stop()
315 if op:
316 self.logger.error("Output from runqemu:\n%s" % op)
317 else:
318 self.logger.error("No output from runqemu.\n")
Andrew Geisslerc926e172021-05-07 16:11:35 -0500319 return False
320
321 # Create the client socket for the QEMU Monitor Control Socket
322 # This will allow us to read status from Qemu if the the process
323 # is still alive
324 self.logger.debug("QMP Initializing to %s" % (qmp_port))
325 # chdir dance for path length issues with unix sockets
326 origpath = os.getcwd()
327 try:
328 os.chdir(os.path.dirname(qmp_port))
329 try:
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500330 from qmp.legacy import QEMUMonitorProtocol
331 self.qmp = QEMUMonitorProtocol(os.path.basename(qmp_port))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500332 except OSError as msg:
333 self.logger.warning("Failed to initialize qemu monitor socket: %s File: %s" % (msg, msg.filename))
334 return False
335
336 self.logger.debug("QMP Connecting to %s" % (qmp_port))
337 if not os.path.exists(qmp_port) and self.is_alive():
338 self.logger.debug("QMP Port does not exist waiting for it to be created")
339 endtime = time.time() + self.runqemutime
340 while not os.path.exists(qmp_port) and self.is_alive() and time.time() < endtime:
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500341 self.logger.info("QMP port does not exist yet!")
342 time.sleep(0.5)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500343 if not os.path.exists(qmp_port) and self.is_alive():
344 self.logger.warning("QMP Port still does not exist but QEMU is alive")
345 return False
346
347 try:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600348 # set timeout value for all QMP calls
349 self.qmp.settimeout(self.runqemutime)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500350 self.qmp.connect()
Andrew Geissler5f350902021-07-23 13:09:54 -0400351 connect_time = time.time()
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500352 self.logger.info("QMP connected to QEMU at %s and took %.2f seconds" %
Andrew Geissler5f350902021-07-23 13:09:54 -0400353 (time.strftime("%D %H:%M:%S"),
354 time.time() - launch_time))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500355 except OSError as msg:
356 self.logger.warning("Failed to connect qemu monitor socket: %s File: %s" % (msg, msg.filename))
357 return False
Patrick Williams7784c422022-11-17 07:29:11 -0600358 except qmp.legacy.QMPError as msg:
Andrew Geisslerc926e172021-05-07 16:11:35 -0500359 self.logger.warning("Failed to communicate with qemu monitor: %s" % (msg))
360 return False
361 finally:
362 os.chdir(origpath)
363
Andrew Geissler09036742021-06-25 14:25:14 -0500364 # We worry that mmap'd libraries may cause page faults which hang the qemu VM for periods
365 # causing failures. Before we "start" qemu, read through it's mapped files to try and
366 # ensure we don't hit page faults later
367 mapdir = "/proc/" + str(self.qemupid) + "/map_files/"
368 try:
369 for f in os.listdir(mapdir):
Andrew Geissler5f350902021-07-23 13:09:54 -0400370 try:
371 linktarget = os.readlink(os.path.join(mapdir, f))
372 if not linktarget.startswith("/") or linktarget.startswith("/dev") or "deleted" in linktarget:
373 continue
374 with open(linktarget, "rb") as readf:
375 data = True
376 while data:
377 data = readf.read(4096)
378 except FileNotFoundError:
Andrew Geissler09036742021-06-25 14:25:14 -0500379 continue
Andrew Geissler09036742021-06-25 14:25:14 -0500380 # Centos7 doesn't allow us to read /map_files/
381 except PermissionError:
382 pass
383
384 # Release the qemu process to continue running
Andrew Geisslerc926e172021-05-07 16:11:35 -0500385 self.run_monitor('cont')
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500386 self.logger.info("QMP released QEMU at %s and took %.2f seconds from connect" %
Andrew Geissler5f350902021-07-23 13:09:54 -0400387 (time.strftime("%D %H:%M:%S"),
388 time.time() - connect_time))
Andrew Geisslerc926e172021-05-07 16:11:35 -0500389
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500390 # We are alive: qemu is running
391 out = self.getOutput(output)
392 netconf = False # network configuration is not required by default
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500393 self.logger.debug("qemu started in %.2f seconds - qemu procces pid is %s (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400394 (time.time() - (endtime - self.runqemutime),
395 self.qemupid, time.strftime("%D %H:%M:%S")))
Andrew Geissler82c905d2020-04-13 13:39:40 -0500396 cmdline = ''
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500397 if get_ip:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500398 with open('/proc/%s/cmdline' % self.qemupid) as p:
399 cmdline = p.read()
400 # It is needed to sanitize the data received
401 # because is possible to have control characters
402 cmdline = re_control_char.sub(' ', cmdline)
403 try:
Brad Bishop19323692019-04-05 15:28:33 -0400404 if self.use_slirp:
Andrew Geissler517393d2023-01-13 08:55:19 -0600405 tcp_ports = cmdline.split("hostfwd=tcp:")[1]
406 ip, tcp_ports = tcp_ports.split(":")[:2]
Brad Bishop19323692019-04-05 15:28:33 -0400407 host_port = tcp_ports[:tcp_ports.find('-')]
Andrew Geissler517393d2023-01-13 08:55:19 -0600408 self.ip = "%s:%s" % (ip, host_port)
Brad Bishop19323692019-04-05 15:28:33 -0400409 else:
410 ips = re.findall(r"((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1])
411 self.ip = ips[0]
412 self.server_ip = ips[1]
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500413 self.logger.debug("qemu cmdline used:\n{}".format(cmdline))
414 except (IndexError, ValueError):
415 # Try to get network configuration from runqemu output
Andrew Geissler595f6302022-01-24 19:11:47 +0000416 match = re.match(r'.*Network configuration: (?:ip=)*([0-9.]+)::([0-9.]+):([0-9.]+).*',
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500417 out, re.MULTILINE | re.DOTALL)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500418 if match:
419 self.ip, self.server_ip, self.netmask = match.groups()
420 # network configuration is required as we couldn't get it
421 # from the runqemu command line, so qemu doesn't run kernel
422 # and guest networking is not configured
423 netconf = True
424 else:
425 self.logger.error("Couldn't get ip from qemu command line and runqemu output! "
426 "Here is the qemu command line used:\n%s\n"
427 "and output from runqemu:\n%s" % (cmdline, out))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500428 self.stop()
429 return False
430
431 self.logger.debug("Target IP: %s" % self.ip)
432 self.logger.debug("Server IP: %s" % self.server_ip)
433
Andrew Geissler82c905d2020-04-13 13:39:40 -0500434 if self.serial_ports >= 2:
435 self.thread = LoggingThread(self.log, self.threadsock, self.logger)
436 self.thread.start()
437 if not self.thread.connection_established.wait(self.boottime):
438 self.logger.error("Didn't receive a console connection from qemu. "
439 "Here is the qemu command line used:\n%s\nand "
440 "output from runqemu:\n%s" % (cmdline, out))
441 self.stop_thread()
442 return False
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500443
444 self.logger.debug("Output from runqemu:\n%s", out)
Brad Bishop316dfdd2018-06-25 12:45:53 -0400445 self.logger.debug("Waiting at most %d seconds for login banner (%s)" %
446 (self.boottime, time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500447 endtime = time.time() + self.boottime
Patrick Williamse760df82023-05-26 11:10:49 -0500448 filelist = [self.server_socket, self.runqemu.stdout]
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500449 reachedlogin = False
450 stopread = False
451 qemusock = None
452 bootlog = b''
453 data = b''
454 while time.time() < endtime and not stopread:
455 try:
Patrick Williamse760df82023-05-26 11:10:49 -0500456 sread, swrite, serror = select.select(filelist, [], [], 5)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500457 except InterruptedError:
458 continue
Patrick Williamse760df82023-05-26 11:10:49 -0500459 for file in sread:
460 if file is self.server_socket:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500461 qemusock, addr = self.server_socket.accept()
Patrick Williamse760df82023-05-26 11:10:49 -0500462 qemusock.setblocking(False)
463 filelist.append(qemusock)
464 filelist.remove(self.server_socket)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500465 self.logger.debug("Connection from %s:%s" % addr)
466 else:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600467 # try to avoid reading only a single character at a time
468 time.sleep(0.1)
Patrick Williamse760df82023-05-26 11:10:49 -0500469 if hasattr(file, 'read'):
470 read = file.read(1024)
471 elif hasattr(file, 'recv'):
472 read = file.recv(1024)
473 else:
474 self.logger.error('Invalid file type: %s\n%s' % (file))
475 read = b''
476
Andrew Geissler20137392023-10-12 04:59:14 -0600477 self.logger.debug2('Partial boot log:\n%s' % (read.decode('utf-8', errors='backslashreplace')))
Patrick Williamse760df82023-05-26 11:10:49 -0500478 data = data + read
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500479 if data:
480 bootlog += data
Andrew Geissler20137392023-10-12 04:59:14 -0600481 self.log(data, extension = ".2")
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500482 data = b''
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500483
Andrew Geissler20137392023-10-12 04:59:14 -0600484 if bytes(self.boot_patterns['search_reached_prompt'], 'utf-8') in bootlog:
Patrick Williamse760df82023-05-26 11:10:49 -0500485 self.server_socket.close()
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500486 self.server_socket = qemusock
487 stopread = True
488 reachedlogin = True
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500489 self.logger.debug("Reached login banner in %.2f seconds (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400490 (time.time() - (endtime - self.boottime),
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500491 time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500492 else:
Brad Bishop316dfdd2018-06-25 12:45:53 -0400493 # no need to check if reachedlogin unless we support multiple connections
494 self.logger.debug("QEMU socket disconnected before login banner reached. (%s)" %
495 time.strftime("%D %H:%M:%S"))
Patrick Williamse760df82023-05-26 11:10:49 -0500496 filelist.remove(file)
497 file.close()
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500498 stopread = True
499
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500500 if not reachedlogin:
Brad Bishop316dfdd2018-06-25 12:45:53 -0400501 if time.time() >= endtime:
Brad Bishop96ff1982019-08-19 13:50:42 -0400502 self.logger.warning("Target didn't reach login banner in %d seconds (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400503 (self.boottime, time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500504 tail = lambda l: "\n".join(l.splitlines()[-25:])
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500505 bootlog = self.decode_qemulog(bootlog)
Andrew Geissler20137392023-10-12 04:59:14 -0600506 self.logger.warning("Last 25 lines of login console (%d):\n%s" % (len(bootlog), tail(bootlog)))
507 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 -0400508 self.logger.warning("Check full boot log: %s" % self.logfile)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500509 self.stop()
Andrew Geissler20137392023-10-12 04:59:14 -0600510 data = True
511 while data:
512 try:
513 time.sleep(1)
514 data = qemusock.recv(1024)
515 self.log(data, extension = ".2")
516 self.logger.warning('Extra log data read: %s\n' % (data.decode('utf-8', errors='backslashreplace')))
517 except Exception as e:
518 self.logger.warning('Extra log data exception %s' % repr(e))
519 data = None
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500520 return False
521
522 # If we are not able to login the tests can continue
523 try:
Andrew Geisslerc3d88e42020-10-02 09:45:00 -0500524 (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120)
Andrew Geissler82c905d2020-04-13 13:39:40 -0500525 if re.search(self.boot_patterns['search_login_succeeded'], output):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500526 self.logged = True
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500527 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 -0500528 if netconf:
529 # configure guest networking
530 cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask)
531 output = self.run_serial(cmd, raw=True)[1]
Brad Bishopf86d0552018-12-04 14:18:15 -0800532 if re.search(r"root@[a-zA-Z0-9\-]+:~#", output):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500533 self.logger.debug("configured ip address %s", self.ip)
534 else:
535 self.logger.debug("Couldn't configure guest networking")
536 else:
Brad Bishop96ff1982019-08-19 13:50:42 -0400537 self.logger.warning("Couldn't login into serial console"
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500538 " as %s using blank password" % self.boot_patterns['send_login_user'].replace("\n", ""))
Brad Bishop96ff1982019-08-19 13:50:42 -0400539 self.logger.warning("The output:\n%s" % output)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500540 except:
Brad Bishop96ff1982019-08-19 13:50:42 -0400541 self.logger.warning("Serial console failed while trying to login")
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500542 return True
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500543
544 def stop(self):
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500545 if hasattr(self, "origchldhandler"):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500546 signal.signal(signal.SIGCHLD, self.origchldhandler)
Brad Bishop1a4b7ee2018-12-16 17:11:34 -0800547 self.stop_thread()
548 self.stop_qemu_system()
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500549 if self.runqemu:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600550 if hasattr(self, "monitorpid"):
551 os.kill(self.monitorpid, signal.SIGKILL)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500552 self.logger.debug("Sending SIGTERM to runqemu")
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600553 try:
554 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
555 except OSError as e:
556 if e.errno != errno.ESRCH:
557 raise
Patrick Williams864cc432023-02-09 14:54:44 -0600558 try:
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500559 outs, errs = self.runqemu.communicate(timeout=self.runqemutime)
Patrick Williams864cc432023-02-09 14:54:44 -0600560 if outs:
561 self.logger.info("Output from runqemu:\n%s", outs.decode("utf-8"))
562 if errs:
563 self.logger.info("Stderr from runqemu:\n%s", errs.decode("utf-8"))
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500564 except subprocess.TimeoutExpired:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500565 self.logger.debug("Sending SIGKILL to runqemu")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500566 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL)
Andrew Geisslerd159c7f2021-09-02 21:05:58 -0500567 if not self.runqemu.stdout.closed:
568 self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout))
Brad Bishopf86d0552018-12-04 14:18:15 -0800569 self.runqemu.stdin.close()
570 self.runqemu.stdout.close()
Andrew Geissler82c905d2020-04-13 13:39:40 -0500571 self.runqemu_exited = True
Brad Bishopf86d0552018-12-04 14:18:15 -0800572
Andrew Geisslerc926e172021-05-07 16:11:35 -0500573 if hasattr(self, 'qmp') and self.qmp:
574 self.qmp.close()
575 self.qmp = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500576 if hasattr(self, 'server_socket') and self.server_socket:
577 self.server_socket.close()
578 self.server_socket = None
Brad Bishopf86d0552018-12-04 14:18:15 -0800579 if hasattr(self, 'threadsock') and self.threadsock:
580 self.threadsock.close()
581 self.threadsock = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500582 self.qemupid = None
583 self.ip = None
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500584 if os.path.exists(self.qemu_pidfile):
Andrew Geissler82c905d2020-04-13 13:39:40 -0500585 try:
586 os.remove(self.qemu_pidfile)
587 except FileNotFoundError as e:
588 # We raced, ignore
589 pass
Brad Bishopf86d0552018-12-04 14:18:15 -0800590 if self.monitorpipe:
591 self.monitorpipe.close()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500592
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500593 def stop_qemu_system(self):
594 if self.qemupid:
595 try:
596 # qemu-system behaves well and a SIGTERM is enough
597 os.kill(self.qemupid, signal.SIGTERM)
598 except ProcessLookupError as e:
Brad Bishop1a4b7ee2018-12-16 17:11:34 -0800599 self.logger.warning('qemu-system ended unexpectedly')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500600
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500601 def stop_thread(self):
602 if self.thread and self.thread.is_alive():
603 self.thread.stop()
604 self.thread.join()
605
Andrew Geisslerc926e172021-05-07 16:11:35 -0500606 def allowexit(self):
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700607 self.canexit = True
Andrew Geisslerc926e172021-05-07 16:11:35 -0500608 if self.thread:
609 self.thread.allowexit()
610
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500611 def restart(self, qemuparams = None):
Brad Bishop96ff1982019-08-19 13:50:42 -0400612 self.logger.warning("Restarting qemu process")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500613 if self.runqemu.poll() is None:
614 self.stop()
615 if self.start(qemuparams):
616 return True
617 return False
618
619 def is_alive(self):
Andrew Geissler82c905d2020-04-13 13:39:40 -0500620 if not self.runqemu or self.runqemu.poll() is not None or self.runqemu_exited:
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500621 return False
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500622 if os.path.isfile(self.qemu_pidfile):
Brad Bishop96ff1982019-08-19 13:50:42 -0400623 # when handling pidfile, qemu creates the file, stat it, lock it and then write to it
624 # so it's possible that the file has been created but the content is empty
625 pidfile_timeout = time.time() + 3
626 while time.time() < pidfile_timeout:
627 with open(self.qemu_pidfile, 'r') as f:
628 qemu_pid = f.read().strip()
629 # file created but not yet written contents
630 if not qemu_pid:
631 time.sleep(0.5)
632 continue
633 else:
634 if os.path.exists("/proc/" + qemu_pid):
635 self.qemupid = int(qemu_pid)
636 return True
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500637 return False
638
Andrew Geissler5f350902021-07-23 13:09:54 -0400639 def run_monitor(self, command, args=None, timeout=60):
640 if hasattr(self, 'qmp') and self.qmp:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600641 self.qmp.settimeout(timeout)
Andrew Geissler5f350902021-07-23 13:09:54 -0400642 if args is not None:
643 return self.qmp.cmd(command, args)
644 else:
645 return self.qmp.cmd(command)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500646
Brad Bishop977dc1a2019-02-06 16:01:43 -0500647 def run_serial(self, command, raw=False, timeout=60):
Patrick Williams92b42cb2022-09-03 06:53:57 -0500648 # Returns (status, output) where status is 1 on success and 0 on error
649
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500650 # We assume target system have echo to get command status
651 if not raw:
652 command = "%s; echo $?\n" % command
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500653
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500654 data = ''
655 status = 0
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600656 self.server_socket.sendall(command.encode('utf-8'))
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500657 start = time.time()
658 end = start + timeout
659 while True:
660 now = time.time()
661 if now >= end:
662 data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout
663 break
664 try:
665 sread, _, _ = select.select([self.server_socket],[],[], end - now)
666 except InterruptedError:
667 continue
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500668 if sread:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600669 # try to avoid reading single character at a time
670 time.sleep(0.1)
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500671 answer = self.server_socket.recv(1024)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500672 if answer:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600673 data += answer.decode('utf-8')
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500674 # Search the prompt to stop
Andrew Geissler82c905d2020-04-13 13:39:40 -0500675 if re.search(self.boot_patterns['search_cmd_finished'], data):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500676 break
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500677 else:
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700678 if self.canexit:
679 return (1, "")
680 raise Exception("No data on serial console socket, connection closed?")
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500681
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500682 if data:
683 if raw:
684 status = 1
685 else:
686 # Remove first line (command line) and last line (prompt)
687 data = data[data.find('$?\r\n')+4:data.rfind('\r\n')]
688 index = data.rfind('\r\n')
689 if index == -1:
690 status_cmd = data
691 data = ""
692 else:
693 status_cmd = data[index+2:]
694 data = data[:index]
695 if (status_cmd == "0"):
696 status = 1
697 return (status, str(data))
698
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500699# This class is for reading data from a socket and passing it to logfunc
700# to be processed. It's completely event driven and has a straightforward
701# event loop. The mechanism for stopping the thread is a simple pipe which
702# will wake up the poll and allow for tearing everything down.
703class LoggingThread(threading.Thread):
704 def __init__(self, logfunc, sock, logger):
705 self.connection_established = threading.Event()
706 self.serversock = sock
707 self.logfunc = logfunc
708 self.logger = logger
709 self.readsock = None
710 self.running = False
Andrew Geisslerc926e172021-05-07 16:11:35 -0500711 self.canexit = False
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500712
713 self.errorevents = select.POLLERR | select.POLLHUP | select.POLLNVAL
714 self.readevents = select.POLLIN | select.POLLPRI
715
716 threading.Thread.__init__(self, target=self.threadtarget)
717
718 def threadtarget(self):
719 try:
720 self.eventloop()
721 finally:
722 self.teardown()
723
724 def run(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500725 self.logger.debug("Starting logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500726 self.readpipe, self.writepipe = os.pipe()
727 threading.Thread.run(self)
728
729 def stop(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500730 self.logger.debug("Stopping logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500731 if self.running:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600732 os.write(self.writepipe, bytes("stop", "utf-8"))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500733
734 def teardown(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500735 self.logger.debug("Tearing down logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500736 self.close_socket(self.serversock)
737
738 if self.readsock is not None:
739 self.close_socket(self.readsock)
740
741 self.close_ignore_error(self.readpipe)
742 self.close_ignore_error(self.writepipe)
743 self.running = False
744
Andrew Geisslerc926e172021-05-07 16:11:35 -0500745 def allowexit(self):
746 self.canexit = True
747
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500748 def eventloop(self):
749 poll = select.poll()
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500750 event_read_mask = self.errorevents | self.readevents
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500751 poll.register(self.serversock.fileno())
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500752 poll.register(self.readpipe, event_read_mask)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500753
754 breakout = False
755 self.running = True
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500756 self.logger.debug("Starting thread event loop")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500757 while not breakout:
758 events = poll.poll()
759 for event in events:
760 # An error occurred, bail out
761 if event[1] & self.errorevents:
762 raise Exception(self.stringify_event(event[1]))
763
764 # Event to stop the thread
765 if self.readpipe == event[0]:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500766 self.logger.debug("Stop event received")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500767 breakout = True
768 break
769
770 # A connection request was received
771 elif self.serversock.fileno() == event[0]:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500772 self.logger.debug("Connection request received")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500773 self.readsock, _ = self.serversock.accept()
774 self.readsock.setblocking(0)
775 poll.unregister(self.serversock.fileno())
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500776 poll.register(self.readsock.fileno(), event_read_mask)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500777
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500778 self.logger.debug("Setting connection established event")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500779 self.connection_established.set()
780
781 # Actual data to be logged
782 elif self.readsock.fileno() == event[0]:
783 data = self.recv(1024)
784 self.logfunc(data)
785
786 # Since the socket is non-blocking make sure to honor EAGAIN
787 # and EWOULDBLOCK.
788 def recv(self, count):
789 try:
790 data = self.readsock.recv(count)
791 except socket.error as e:
792 if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK:
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700793 return b''
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500794 else:
795 raise
796
797 if data is None:
798 raise Exception("No data on read ready socket")
799 elif not data:
800 # This actually means an orderly shutdown
801 # happened. But for this code it counts as an
802 # error since the connection shouldn't go away
803 # until qemu exits.
Andrew Geisslerc926e172021-05-07 16:11:35 -0500804 if not self.canexit:
805 raise Exception("Console connection closed unexpectedly")
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700806 return b''
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500807
808 return data
809
810 def stringify_event(self, event):
811 val = ''
812 if select.POLLERR == event:
813 val = 'POLLER'
814 elif select.POLLHUP == event:
815 val = 'POLLHUP'
816 elif select.POLLNVAL == event:
817 val = 'POLLNVAL'
818 return val
819
820 def close_socket(self, sock):
821 sock.shutdown(socket.SHUT_RDWR)
822 sock.close()
823
824 def close_ignore_error(self, fd):
825 try:
826 os.close(fd)
827 except OSError:
828 pass