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 %s 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 %s 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 self.qmp.connect() 354 connect_time = time.time() 355 self.logger.info("QMP connected to QEMU at %s and took %s seconds" % 356 (time.strftime("%D %H:%M:%S"), 357 time.time() - launch_time)) 358 except OSError as msg: 359 self.logger.warning("Failed to connect qemu monitor socket: %s File: %s" % (msg, msg.filename)) 360 return False 361 except qmp.legacy.QMPError as msg: 362 self.logger.warning("Failed to communicate with qemu monitor: %s" % (msg)) 363 return False 364 finally: 365 os.chdir(origpath) 366 367 # We worry that mmap'd libraries may cause page faults which hang the qemu VM for periods 368 # causing failures. Before we "start" qemu, read through it's mapped files to try and 369 # ensure we don't hit page faults later 370 mapdir = "/proc/" + str(self.qemupid) + "/map_files/" 371 try: 372 for f in os.listdir(mapdir): 373 try: 374 linktarget = os.readlink(os.path.join(mapdir, f)) 375 if not linktarget.startswith("/") or linktarget.startswith("/dev") or "deleted" in linktarget: 376 continue 377 with open(linktarget, "rb") as readf: 378 data = True 379 while data: 380 data = readf.read(4096) 381 except FileNotFoundError: 382 continue 383 # Centos7 doesn't allow us to read /map_files/ 384 except PermissionError: 385 pass 386 387 # Release the qemu process to continue running 388 self.run_monitor('cont') 389 self.logger.info("QMP released QEMU at %s and took %s seconds from connect" % 390 (time.strftime("%D %H:%M:%S"), 391 time.time() - connect_time)) 392 393 # We are alive: qemu is running 394 out = self.getOutput(output) 395 netconf = False # network configuration is not required by default 396 self.logger.debug("qemu started in %s seconds - qemu procces pid is %s (%s)" % 397 (time.time() - (endtime - self.runqemutime), 398 self.qemupid, time.strftime("%D %H:%M:%S"))) 399 cmdline = '' 400 if get_ip: 401 with open('/proc/%s/cmdline' % self.qemupid) as p: 402 cmdline = p.read() 403 # It is needed to sanitize the data received 404 # because is possible to have control characters 405 cmdline = re_control_char.sub(' ', cmdline) 406 try: 407 if self.use_slirp: 408 tcp_ports = cmdline.split("hostfwd=tcp:")[1] 409 ip, tcp_ports = tcp_ports.split(":")[:2] 410 host_port = tcp_ports[:tcp_ports.find('-')] 411 self.ip = "%s:%s" % (ip, host_port) 412 else: 413 ips = re.findall(r"((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1]) 414 self.ip = ips[0] 415 self.server_ip = ips[1] 416 self.logger.debug("qemu cmdline used:\n{}".format(cmdline)) 417 except (IndexError, ValueError): 418 # Try to get network configuration from runqemu output 419 match = re.match(r'.*Network configuration: (?:ip=)*([0-9.]+)::([0-9.]+):([0-9.]+).*', 420 out, re.MULTILINE|re.DOTALL) 421 if match: 422 self.ip, self.server_ip, self.netmask = match.groups() 423 # network configuration is required as we couldn't get it 424 # from the runqemu command line, so qemu doesn't run kernel 425 # and guest networking is not configured 426 netconf = True 427 else: 428 self.logger.error("Couldn't get ip from qemu command line and runqemu output! " 429 "Here is the qemu command line used:\n%s\n" 430 "and output from runqemu:\n%s" % (cmdline, out)) 431 self._dump_host() 432 self.stop() 433 return False 434 435 self.logger.debug("Target IP: %s" % self.ip) 436 self.logger.debug("Server IP: %s" % self.server_ip) 437 438 if self.serial_ports >= 2: 439 self.thread = LoggingThread(self.log, self.threadsock, self.logger) 440 self.thread.start() 441 if not self.thread.connection_established.wait(self.boottime): 442 self.logger.error("Didn't receive a console connection from qemu. " 443 "Here is the qemu command line used:\n%s\nand " 444 "output from runqemu:\n%s" % (cmdline, out)) 445 self.stop_thread() 446 return False 447 448 self.logger.debug("Output from runqemu:\n%s", out) 449 self.logger.debug("Waiting at most %d seconds for login banner (%s)" % 450 (self.boottime, time.strftime("%D %H:%M:%S"))) 451 endtime = time.time() + self.boottime 452 socklist = [self.server_socket] 453 reachedlogin = False 454 stopread = False 455 qemusock = None 456 bootlog = b'' 457 data = b'' 458 while time.time() < endtime and not stopread: 459 try: 460 sread, swrite, serror = select.select(socklist, [], [], 5) 461 except InterruptedError: 462 continue 463 for sock in sread: 464 if sock is self.server_socket: 465 qemusock, addr = self.server_socket.accept() 466 qemusock.setblocking(0) 467 socklist.append(qemusock) 468 socklist.remove(self.server_socket) 469 self.logger.debug("Connection from %s:%s" % addr) 470 else: 471 data = data + sock.recv(1024) 472 if data: 473 bootlog += data 474 if self.serial_ports < 2: 475 # this socket has mixed console/kernel data, log it to logfile 476 self.log(data) 477 478 data = b'' 479 480 decodedlog = self.decode_qemulog(bootlog) 481 if self.boot_patterns['search_reached_prompt'] in decodedlog: 482 self.server_socket = qemusock 483 stopread = True 484 reachedlogin = True 485 self.logger.debug("Reached login banner in %s seconds (%s, %s)" % 486 (time.time() - (endtime - self.boottime), 487 time.strftime("%D %H:%M:%S"), time.time())) 488 else: 489 # no need to check if reachedlogin unless we support multiple connections 490 self.logger.debug("QEMU socket disconnected before login banner reached. (%s)" % 491 time.strftime("%D %H:%M:%S")) 492 socklist.remove(sock) 493 sock.close() 494 stopread = True 495 496 if not reachedlogin: 497 if time.time() >= endtime: 498 self.logger.warning("Target didn't reach login banner in %d seconds (%s)" % 499 (self.boottime, time.strftime("%D %H:%M:%S"))) 500 tail = lambda l: "\n".join(l.splitlines()[-25:]) 501 bootlog = self.decode_qemulog(bootlog) 502 # in case bootlog is empty, use tail qemu log store at self.msg 503 lines = tail(bootlog if bootlog else self.msg) 504 self.logger.warning("Last 25 lines of text (%d):\n%s" % (len(bootlog), lines)) 505 self.logger.warning("Check full boot log: %s" % self.logfile) 506 self._dump_host() 507 self.stop() 508 return False 509 510 # If we are not able to login the tests can continue 511 try: 512 (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120) 513 if re.search(self.boot_patterns['search_login_succeeded'], output): 514 self.logged = True 515 self.logger.debug("Logged as root in serial console") 516 if netconf: 517 # configure guest networking 518 cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask) 519 output = self.run_serial(cmd, raw=True)[1] 520 if re.search(r"root@[a-zA-Z0-9\-]+:~#", output): 521 self.logger.debug("configured ip address %s", self.ip) 522 else: 523 self.logger.debug("Couldn't configure guest networking") 524 else: 525 self.logger.warning("Couldn't login into serial console" 526 " as root using blank password") 527 self.logger.warning("The output:\n%s" % output) 528 except: 529 self.logger.warning("Serial console failed while trying to login") 530 return True 531 532 def stop(self): 533 if hasattr(self, "origchldhandler"): 534 signal.signal(signal.SIGCHLD, self.origchldhandler) 535 self.stop_thread() 536 self.stop_qemu_system() 537 if self.runqemu: 538 if hasattr(self, "monitorpid"): 539 os.kill(self.monitorpid, signal.SIGKILL) 540 self.logger.debug("Sending SIGTERM to runqemu") 541 try: 542 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) 543 except OSError as e: 544 if e.errno != errno.ESRCH: 545 raise 546 endtime = time.time() + self.runqemutime 547 while self.runqemu.poll() is None and time.time() < endtime: 548 time.sleep(1) 549 if self.runqemu.poll() is None: 550 self.logger.debug("Sending SIGKILL to runqemu") 551 os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL) 552 if not self.runqemu.stdout.closed: 553 self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout)) 554 self.runqemu.stdin.close() 555 self.runqemu.stdout.close() 556 self.runqemu_exited = True 557 558 if hasattr(self, 'qmp') and self.qmp: 559 self.qmp.close() 560 self.qmp = None 561 if hasattr(self, 'server_socket') and self.server_socket: 562 self.server_socket.close() 563 self.server_socket = None 564 if hasattr(self, 'threadsock') and self.threadsock: 565 self.threadsock.close() 566 self.threadsock = None 567 self.qemupid = None 568 self.ip = None 569 if os.path.exists(self.qemu_pidfile): 570 try: 571 os.remove(self.qemu_pidfile) 572 except FileNotFoundError as e: 573 # We raced, ignore 574 pass 575 if self.monitorpipe: 576 self.monitorpipe.close() 577 578 def stop_qemu_system(self): 579 if self.qemupid: 580 try: 581 # qemu-system behaves well and a SIGTERM is enough 582 os.kill(self.qemupid, signal.SIGTERM) 583 except ProcessLookupError as e: 584 self.logger.warning('qemu-system ended unexpectedly') 585 586 def stop_thread(self): 587 if self.thread and self.thread.is_alive(): 588 self.thread.stop() 589 self.thread.join() 590 591 def allowexit(self): 592 self.canexit = True 593 if self.thread: 594 self.thread.allowexit() 595 596 def restart(self, qemuparams = None): 597 self.logger.warning("Restarting qemu process") 598 if self.runqemu.poll() is None: 599 self.stop() 600 if self.start(qemuparams): 601 return True 602 return False 603 604 def is_alive(self): 605 if not self.runqemu or self.runqemu.poll() is not None or self.runqemu_exited: 606 return False 607 if os.path.isfile(self.qemu_pidfile): 608 # when handling pidfile, qemu creates the file, stat it, lock it and then write to it 609 # so it's possible that the file has been created but the content is empty 610 pidfile_timeout = time.time() + 3 611 while time.time() < pidfile_timeout: 612 with open(self.qemu_pidfile, 'r') as f: 613 qemu_pid = f.read().strip() 614 # file created but not yet written contents 615 if not qemu_pid: 616 time.sleep(0.5) 617 continue 618 else: 619 if os.path.exists("/proc/" + qemu_pid): 620 self.qemupid = int(qemu_pid) 621 return True 622 return False 623 624 def run_monitor(self, command, args=None, timeout=60): 625 if hasattr(self, 'qmp') and self.qmp: 626 if args is not None: 627 return self.qmp.cmd(command, args) 628 else: 629 return self.qmp.cmd(command) 630 631 def run_serial(self, command, raw=False, timeout=60): 632 # Returns (status, output) where status is 1 on success and 0 on error 633 634 # We assume target system have echo to get command status 635 if not raw: 636 command = "%s; echo $?\n" % command 637 638 data = '' 639 status = 0 640 self.server_socket.sendall(command.encode('utf-8')) 641 start = time.time() 642 end = start + timeout 643 while True: 644 now = time.time() 645 if now >= end: 646 data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout 647 break 648 try: 649 sread, _, _ = select.select([self.server_socket],[],[], end - now) 650 except InterruptedError: 651 continue 652 if sread: 653 answer = self.server_socket.recv(1024) 654 if answer: 655 data += answer.decode('utf-8') 656 # Search the prompt to stop 657 if re.search(self.boot_patterns['search_cmd_finished'], data): 658 break 659 else: 660 if self.canexit: 661 return (1, "") 662 raise Exception("No data on serial console socket, connection closed?") 663 664 if data: 665 if raw: 666 status = 1 667 else: 668 # Remove first line (command line) and last line (prompt) 669 data = data[data.find('$?\r\n')+4:data.rfind('\r\n')] 670 index = data.rfind('\r\n') 671 if index == -1: 672 status_cmd = data 673 data = "" 674 else: 675 status_cmd = data[index+2:] 676 data = data[:index] 677 if (status_cmd == "0"): 678 status = 1 679 return (status, str(data)) 680 681 682 def _dump_host(self): 683 self.host_dumper.create_dir("qemu") 684 self.logger.warning("Qemu ended unexpectedly, dump data from host" 685 " is in %s" % self.host_dumper.dump_dir) 686 self.host_dumper.dump_host() 687 688# This class is for reading data from a socket and passing it to logfunc 689# to be processed. It's completely event driven and has a straightforward 690# event loop. The mechanism for stopping the thread is a simple pipe which 691# will wake up the poll and allow for tearing everything down. 692class LoggingThread(threading.Thread): 693 def __init__(self, logfunc, sock, logger): 694 self.connection_established = threading.Event() 695 self.serversock = sock 696 self.logfunc = logfunc 697 self.logger = logger 698 self.readsock = None 699 self.running = False 700 self.canexit = False 701 702 self.errorevents = select.POLLERR | select.POLLHUP | select.POLLNVAL 703 self.readevents = select.POLLIN | select.POLLPRI 704 705 threading.Thread.__init__(self, target=self.threadtarget) 706 707 def threadtarget(self): 708 try: 709 self.eventloop() 710 finally: 711 self.teardown() 712 713 def run(self): 714 self.logger.debug("Starting logging thread") 715 self.readpipe, self.writepipe = os.pipe() 716 threading.Thread.run(self) 717 718 def stop(self): 719 self.logger.debug("Stopping logging thread") 720 if self.running: 721 os.write(self.writepipe, bytes("stop", "utf-8")) 722 723 def teardown(self): 724 self.logger.debug("Tearing down logging thread") 725 self.close_socket(self.serversock) 726 727 if self.readsock is not None: 728 self.close_socket(self.readsock) 729 730 self.close_ignore_error(self.readpipe) 731 self.close_ignore_error(self.writepipe) 732 self.running = False 733 734 def allowexit(self): 735 self.canexit = True 736 737 def eventloop(self): 738 poll = select.poll() 739 event_read_mask = self.errorevents | self.readevents 740 poll.register(self.serversock.fileno()) 741 poll.register(self.readpipe, event_read_mask) 742 743 breakout = False 744 self.running = True 745 self.logger.debug("Starting thread event loop") 746 while not breakout: 747 events = poll.poll() 748 for event in events: 749 # An error occurred, bail out 750 if event[1] & self.errorevents: 751 raise Exception(self.stringify_event(event[1])) 752 753 # Event to stop the thread 754 if self.readpipe == event[0]: 755 self.logger.debug("Stop event received") 756 breakout = True 757 break 758 759 # A connection request was received 760 elif self.serversock.fileno() == event[0]: 761 self.logger.debug("Connection request received") 762 self.readsock, _ = self.serversock.accept() 763 self.readsock.setblocking(0) 764 poll.unregister(self.serversock.fileno()) 765 poll.register(self.readsock.fileno(), event_read_mask) 766 767 self.logger.debug("Setting connection established event") 768 self.connection_established.set() 769 770 # Actual data to be logged 771 elif self.readsock.fileno() == event[0]: 772 data = self.recv(1024) 773 self.logfunc(data) 774 775 # Since the socket is non-blocking make sure to honor EAGAIN 776 # and EWOULDBLOCK. 777 def recv(self, count): 778 try: 779 data = self.readsock.recv(count) 780 except socket.error as e: 781 if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK: 782 return b'' 783 else: 784 raise 785 786 if data is None: 787 raise Exception("No data on read ready socket") 788 elif not data: 789 # This actually means an orderly shutdown 790 # happened. But for this code it counts as an 791 # error since the connection shouldn't go away 792 # until qemu exits. 793 if not self.canexit: 794 raise Exception("Console connection closed unexpectedly") 795 return b'' 796 797 return data 798 799 def stringify_event(self, event): 800 val = '' 801 if select.POLLERR == event: 802 val = 'POLLER' 803 elif select.POLLHUP == event: 804 val = 'POLLHUP' 805 elif select.POLLNVAL == event: 806 val = 'POLLNVAL' 807 return val 808 809 def close_socket(self, sock): 810 sock.shutdown(socket.SHUT_RDWR) 811 sock.close() 812 813 def close_ignore_error(self, fd): 814 try: 815 os.close(fd) 816 except OSError: 817 pass 818