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