blob: a52fa41768f6a810d31026597a1a5a5ddc78d05f [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
Andrew Geissler20137392023-10-12 04:59:14 -0600448 newlinetime = time.time() + 120
Patrick Williamse760df82023-05-26 11:10:49 -0500449 filelist = [self.server_socket, self.runqemu.stdout]
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500450 reachedlogin = False
451 stopread = False
Andrew Geissler20137392023-10-12 04:59:14 -0600452 sentnewlines = False
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500453 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
Andrew Geissler20137392023-10-12 04:59:14 -0600461 # With the 6.5 kernel, the serial port getty sometimes fails to appear, the data
462 # appears lost in some buffer somewhere. Wait two minutes, then if we've not had a login,
463 # try and provoke one. This is a workaround until we can work out the root cause.
464 if time.time() > newlinetime and not sentnewlines:
465 self.logger.warning('Probing the serial port to wake it up!')
466 try:
467 self.server_socket.sendall(bytes("\n\n", "utf-8"))
468 sentnewlines = True
469 except BrokenPipeError as e:
470 self.logger.debug('Probe failed %s' % repr(e))
Patrick Williamse760df82023-05-26 11:10:49 -0500471 for file in sread:
472 if file is self.server_socket:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500473 qemusock, addr = self.server_socket.accept()
Patrick Williamse760df82023-05-26 11:10:49 -0500474 qemusock.setblocking(False)
475 filelist.append(qemusock)
476 filelist.remove(self.server_socket)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500477 self.logger.debug("Connection from %s:%s" % addr)
478 else:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600479 # try to avoid reading only a single character at a time
480 time.sleep(0.1)
Patrick Williamse760df82023-05-26 11:10:49 -0500481 if hasattr(file, 'read'):
482 read = file.read(1024)
483 elif hasattr(file, 'recv'):
484 read = file.recv(1024)
485 else:
486 self.logger.error('Invalid file type: %s\n%s' % (file))
487 read = b''
488
Andrew Geissler20137392023-10-12 04:59:14 -0600489 self.logger.debug2('Partial boot log:\n%s' % (read.decode('utf-8', errors='backslashreplace')))
Patrick Williamse760df82023-05-26 11:10:49 -0500490 data = data + read
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500491 if data:
492 bootlog += data
Andrew Geissler20137392023-10-12 04:59:14 -0600493 self.log(data, extension = ".2")
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500494 data = b''
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500495
Andrew Geissler20137392023-10-12 04:59:14 -0600496 if bytes(self.boot_patterns['search_reached_prompt'], 'utf-8') in bootlog:
Patrick Williamse760df82023-05-26 11:10:49 -0500497 self.server_socket.close()
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500498 self.server_socket = qemusock
499 stopread = True
500 reachedlogin = True
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500501 self.logger.debug("Reached login banner in %.2f seconds (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400502 (time.time() - (endtime - self.boottime),
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500503 time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500504 else:
Brad Bishop316dfdd2018-06-25 12:45:53 -0400505 # no need to check if reachedlogin unless we support multiple connections
506 self.logger.debug("QEMU socket disconnected before login banner reached. (%s)" %
507 time.strftime("%D %H:%M:%S"))
Patrick Williamse760df82023-05-26 11:10:49 -0500508 filelist.remove(file)
509 file.close()
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500510 stopread = True
511
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500512 if not reachedlogin:
Brad Bishop316dfdd2018-06-25 12:45:53 -0400513 if time.time() >= endtime:
Brad Bishop96ff1982019-08-19 13:50:42 -0400514 self.logger.warning("Target didn't reach login banner in %d seconds (%s)" %
Brad Bishop316dfdd2018-06-25 12:45:53 -0400515 (self.boottime, time.strftime("%D %H:%M:%S")))
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500516 tail = lambda l: "\n".join(l.splitlines()[-25:])
Andrew Geissler87f5cff2022-09-30 13:13:31 -0500517 bootlog = self.decode_qemulog(bootlog)
Andrew Geissler20137392023-10-12 04:59:14 -0600518 self.logger.warning("Last 25 lines of login console (%d):\n%s" % (len(bootlog), tail(bootlog)))
519 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 -0400520 self.logger.warning("Check full boot log: %s" % self.logfile)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500521 self.stop()
Andrew Geissler20137392023-10-12 04:59:14 -0600522 data = True
523 while data:
524 try:
525 time.sleep(1)
526 data = qemusock.recv(1024)
527 self.log(data, extension = ".2")
528 self.logger.warning('Extra log data read: %s\n' % (data.decode('utf-8', errors='backslashreplace')))
529 except Exception as e:
530 self.logger.warning('Extra log data exception %s' % repr(e))
531 data = None
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500532 return False
533
534 # If we are not able to login the tests can continue
535 try:
Andrew Geisslerc3d88e42020-10-02 09:45:00 -0500536 (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120)
Andrew Geissler82c905d2020-04-13 13:39:40 -0500537 if re.search(self.boot_patterns['search_login_succeeded'], output):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500538 self.logged = True
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500539 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 -0500540 if netconf:
541 # configure guest networking
542 cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask)
543 output = self.run_serial(cmd, raw=True)[1]
Brad Bishopf86d0552018-12-04 14:18:15 -0800544 if re.search(r"root@[a-zA-Z0-9\-]+:~#", output):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500545 self.logger.debug("configured ip address %s", self.ip)
546 else:
547 self.logger.debug("Couldn't configure guest networking")
548 else:
Brad Bishop96ff1982019-08-19 13:50:42 -0400549 self.logger.warning("Couldn't login into serial console"
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500550 " as %s using blank password" % self.boot_patterns['send_login_user'].replace("\n", ""))
Brad Bishop96ff1982019-08-19 13:50:42 -0400551 self.logger.warning("The output:\n%s" % output)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500552 except:
Brad Bishop96ff1982019-08-19 13:50:42 -0400553 self.logger.warning("Serial console failed while trying to login")
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500554 return True
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500555
556 def stop(self):
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500557 if hasattr(self, "origchldhandler"):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500558 signal.signal(signal.SIGCHLD, self.origchldhandler)
Brad Bishop1a4b7ee2018-12-16 17:11:34 -0800559 self.stop_thread()
560 self.stop_qemu_system()
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500561 if self.runqemu:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600562 if hasattr(self, "monitorpid"):
563 os.kill(self.monitorpid, signal.SIGKILL)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500564 self.logger.debug("Sending SIGTERM to runqemu")
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600565 try:
566 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
567 except OSError as e:
568 if e.errno != errno.ESRCH:
569 raise
Patrick Williams864cc432023-02-09 14:54:44 -0600570 try:
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500571 outs, errs = self.runqemu.communicate(timeout=self.runqemutime)
Patrick Williams864cc432023-02-09 14:54:44 -0600572 if outs:
573 self.logger.info("Output from runqemu:\n%s", outs.decode("utf-8"))
574 if errs:
575 self.logger.info("Stderr from runqemu:\n%s", errs.decode("utf-8"))
Patrick Williams8e7b46e2023-05-01 14:19:06 -0500576 except subprocess.TimeoutExpired:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500577 self.logger.debug("Sending SIGKILL to runqemu")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500578 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL)
Andrew Geisslerd159c7f2021-09-02 21:05:58 -0500579 if not self.runqemu.stdout.closed:
580 self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout))
Brad Bishopf86d0552018-12-04 14:18:15 -0800581 self.runqemu.stdin.close()
582 self.runqemu.stdout.close()
Andrew Geissler82c905d2020-04-13 13:39:40 -0500583 self.runqemu_exited = True
Brad Bishopf86d0552018-12-04 14:18:15 -0800584
Andrew Geisslerc926e172021-05-07 16:11:35 -0500585 if hasattr(self, 'qmp') and self.qmp:
586 self.qmp.close()
587 self.qmp = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500588 if hasattr(self, 'server_socket') and self.server_socket:
589 self.server_socket.close()
590 self.server_socket = None
Brad Bishopf86d0552018-12-04 14:18:15 -0800591 if hasattr(self, 'threadsock') and self.threadsock:
592 self.threadsock.close()
593 self.threadsock = None
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500594 self.qemupid = None
595 self.ip = None
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500596 if os.path.exists(self.qemu_pidfile):
Andrew Geissler82c905d2020-04-13 13:39:40 -0500597 try:
598 os.remove(self.qemu_pidfile)
599 except FileNotFoundError as e:
600 # We raced, ignore
601 pass
Brad Bishopf86d0552018-12-04 14:18:15 -0800602 if self.monitorpipe:
603 self.monitorpipe.close()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500604
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500605 def stop_qemu_system(self):
606 if self.qemupid:
607 try:
608 # qemu-system behaves well and a SIGTERM is enough
609 os.kill(self.qemupid, signal.SIGTERM)
610 except ProcessLookupError as e:
Brad Bishop1a4b7ee2018-12-16 17:11:34 -0800611 self.logger.warning('qemu-system ended unexpectedly')
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500612
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500613 def stop_thread(self):
614 if self.thread and self.thread.is_alive():
615 self.thread.stop()
616 self.thread.join()
617
Andrew Geisslerc926e172021-05-07 16:11:35 -0500618 def allowexit(self):
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700619 self.canexit = True
Andrew Geisslerc926e172021-05-07 16:11:35 -0500620 if self.thread:
621 self.thread.allowexit()
622
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500623 def restart(self, qemuparams = None):
Brad Bishop96ff1982019-08-19 13:50:42 -0400624 self.logger.warning("Restarting qemu process")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500625 if self.runqemu.poll() is None:
626 self.stop()
627 if self.start(qemuparams):
628 return True
629 return False
630
631 def is_alive(self):
Andrew Geissler82c905d2020-04-13 13:39:40 -0500632 if not self.runqemu or self.runqemu.poll() is not None or self.runqemu_exited:
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500633 return False
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500634 if os.path.isfile(self.qemu_pidfile):
Brad Bishop96ff1982019-08-19 13:50:42 -0400635 # when handling pidfile, qemu creates the file, stat it, lock it and then write to it
636 # so it's possible that the file has been created but the content is empty
637 pidfile_timeout = time.time() + 3
638 while time.time() < pidfile_timeout:
639 with open(self.qemu_pidfile, 'r') as f:
640 qemu_pid = f.read().strip()
641 # file created but not yet written contents
642 if not qemu_pid:
643 time.sleep(0.5)
644 continue
645 else:
646 if os.path.exists("/proc/" + qemu_pid):
647 self.qemupid = int(qemu_pid)
648 return True
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500649 return False
650
Andrew Geissler5f350902021-07-23 13:09:54 -0400651 def run_monitor(self, command, args=None, timeout=60):
652 if hasattr(self, 'qmp') and self.qmp:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600653 self.qmp.settimeout(timeout)
Andrew Geissler5f350902021-07-23 13:09:54 -0400654 if args is not None:
655 return self.qmp.cmd(command, args)
656 else:
657 return self.qmp.cmd(command)
Andrew Geisslerc926e172021-05-07 16:11:35 -0500658
Brad Bishop977dc1a2019-02-06 16:01:43 -0500659 def run_serial(self, command, raw=False, timeout=60):
Patrick Williams92b42cb2022-09-03 06:53:57 -0500660 # Returns (status, output) where status is 1 on success and 0 on error
661
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500662 # We assume target system have echo to get command status
663 if not raw:
664 command = "%s; echo $?\n" % command
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500665
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500666 data = ''
667 status = 0
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600668 self.server_socket.sendall(command.encode('utf-8'))
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500669 start = time.time()
670 end = start + timeout
671 while True:
672 now = time.time()
673 if now >= end:
674 data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout
675 break
676 try:
677 sread, _, _ = select.select([self.server_socket],[],[], end - now)
678 except InterruptedError:
679 continue
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500680 if sread:
Andrew Geissler6aa7eec2023-03-03 12:41:14 -0600681 # try to avoid reading single character at a time
682 time.sleep(0.1)
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500683 answer = self.server_socket.recv(1024)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500684 if answer:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600685 data += answer.decode('utf-8')
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500686 # Search the prompt to stop
Andrew Geissler82c905d2020-04-13 13:39:40 -0500687 if re.search(self.boot_patterns['search_cmd_finished'], data):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500688 break
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500689 else:
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700690 if self.canexit:
691 return (1, "")
692 raise Exception("No data on serial console socket, connection closed?")
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500693
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500694 if data:
695 if raw:
696 status = 1
697 else:
698 # Remove first line (command line) and last line (prompt)
699 data = data[data.find('$?\r\n')+4:data.rfind('\r\n')]
700 index = data.rfind('\r\n')
701 if index == -1:
702 status_cmd = data
703 data = ""
704 else:
705 status_cmd = data[index+2:]
706 data = data[:index]
707 if (status_cmd == "0"):
708 status = 1
709 return (status, str(data))
710
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500711# This class is for reading data from a socket and passing it to logfunc
712# to be processed. It's completely event driven and has a straightforward
713# event loop. The mechanism for stopping the thread is a simple pipe which
714# will wake up the poll and allow for tearing everything down.
715class LoggingThread(threading.Thread):
716 def __init__(self, logfunc, sock, logger):
717 self.connection_established = threading.Event()
718 self.serversock = sock
719 self.logfunc = logfunc
720 self.logger = logger
721 self.readsock = None
722 self.running = False
Andrew Geisslerc926e172021-05-07 16:11:35 -0500723 self.canexit = False
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500724
725 self.errorevents = select.POLLERR | select.POLLHUP | select.POLLNVAL
726 self.readevents = select.POLLIN | select.POLLPRI
727
728 threading.Thread.__init__(self, target=self.threadtarget)
729
730 def threadtarget(self):
731 try:
732 self.eventloop()
733 finally:
734 self.teardown()
735
736 def run(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500737 self.logger.debug("Starting logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500738 self.readpipe, self.writepipe = os.pipe()
739 threading.Thread.run(self)
740
741 def stop(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500742 self.logger.debug("Stopping logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500743 if self.running:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600744 os.write(self.writepipe, bytes("stop", "utf-8"))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500745
746 def teardown(self):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500747 self.logger.debug("Tearing down logging thread")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500748 self.close_socket(self.serversock)
749
750 if self.readsock is not None:
751 self.close_socket(self.readsock)
752
753 self.close_ignore_error(self.readpipe)
754 self.close_ignore_error(self.writepipe)
755 self.running = False
756
Andrew Geisslerc926e172021-05-07 16:11:35 -0500757 def allowexit(self):
758 self.canexit = True
759
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500760 def eventloop(self):
761 poll = select.poll()
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500762 event_read_mask = self.errorevents | self.readevents
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500763 poll.register(self.serversock.fileno())
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500764 poll.register(self.readpipe, event_read_mask)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500765
766 breakout = False
767 self.running = True
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500768 self.logger.debug("Starting thread event loop")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500769 while not breakout:
770 events = poll.poll()
771 for event in events:
772 # An error occurred, bail out
773 if event[1] & self.errorevents:
774 raise Exception(self.stringify_event(event[1]))
775
776 # Event to stop the thread
777 if self.readpipe == event[0]:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500778 self.logger.debug("Stop event received")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500779 breakout = True
780 break
781
782 # A connection request was received
783 elif self.serversock.fileno() == event[0]:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500784 self.logger.debug("Connection request received")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500785 self.readsock, _ = self.serversock.accept()
786 self.readsock.setblocking(0)
787 poll.unregister(self.serversock.fileno())
Patrick Williamsf1e5d692016-03-30 15:21:19 -0500788 poll.register(self.readsock.fileno(), event_read_mask)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500789
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500790 self.logger.debug("Setting connection established event")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500791 self.connection_established.set()
792
793 # Actual data to be logged
794 elif self.readsock.fileno() == event[0]:
795 data = self.recv(1024)
796 self.logfunc(data)
797
798 # Since the socket is non-blocking make sure to honor EAGAIN
799 # and EWOULDBLOCK.
800 def recv(self, count):
801 try:
802 data = self.readsock.recv(count)
803 except socket.error as e:
804 if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK:
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700805 return b''
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500806 else:
807 raise
808
809 if data is None:
810 raise Exception("No data on read ready socket")
811 elif not data:
812 # This actually means an orderly shutdown
813 # happened. But for this code it counts as an
814 # error since the connection shouldn't go away
815 # until qemu exits.
Andrew Geisslerc926e172021-05-07 16:11:35 -0500816 if not self.canexit:
817 raise Exception("Console connection closed unexpectedly")
William A. Kennington IIIac69b482021-06-02 12:28:27 -0700818 return b''
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500819
820 return data
821
822 def stringify_event(self, event):
823 val = ''
824 if select.POLLERR == event:
825 val = 'POLLER'
826 elif select.POLLHUP == event:
827 val = 'POLLHUP'
828 elif select.POLLNVAL == event:
829 val = 'POLLNVAL'
830 return val
831
832 def close_socket(self, sock):
833 sock.shutdown(socket.SHUT_RDWR)
834 sock.close()
835
836 def close_ignore_error(self, fd):
837 try:
838 os.close(fd)
839 except OSError:
840 pass