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