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