diff options
| -rw-r--r-- | meta/lib/oeqa/utils/qemurunner.py | 90 |
1 files changed, 45 insertions, 45 deletions
diff --git a/meta/lib/oeqa/utils/qemurunner.py b/meta/lib/oeqa/utils/qemurunner.py index 54312fb94c..6ee52a2f1e 100644 --- a/meta/lib/oeqa/utils/qemurunner.py +++ b/meta/lib/oeqa/utils/qemurunner.py | |||
| @@ -17,11 +17,8 @@ import errno | |||
| 17 | import string | 17 | import string |
| 18 | import threading | 18 | import threading |
| 19 | import codecs | 19 | import codecs |
| 20 | from oeqa.utils.dump import HostDumper | ||
| 21 | |||
| 22 | import logging | 20 | import logging |
| 23 | logger = logging.getLogger("BitBake.QemuRunner") | 21 | from oeqa.utils.dump import HostDumper |
| 24 | logger.addHandler(logging.StreamHandler()) | ||
| 25 | 22 | ||
| 26 | # Get Unicode non printable control chars | 23 | # Get Unicode non printable control chars |
| 27 | control_range = list(range(0,32))+list(range(127,160)) | 24 | control_range = list(range(0,32))+list(range(127,160)) |
| @@ -58,6 +55,9 @@ class QemuRunner: | |||
| 58 | self.runqemutime = 120 | 55 | self.runqemutime = 120 |
| 59 | self.host_dumper = HostDumper(dump_host_cmds, dump_dir) | 56 | self.host_dumper = HostDumper(dump_host_cmds, dump_dir) |
| 60 | 57 | ||
| 58 | self.logger = logging.getLogger("BitBake.QemuRunner") | ||
| 59 | self.logger.addHandler(logging.StreamHandler(sys.stdout)) | ||
| 60 | |||
| 61 | def create_socket(self): | 61 | def create_socket(self): |
| 62 | try: | 62 | try: |
| 63 | sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM) | 63 | sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM) |
| @@ -65,7 +65,7 @@ class QemuRunner: | |||
| 65 | sock.bind(("127.0.0.1",0)) | 65 | sock.bind(("127.0.0.1",0)) |
| 66 | sock.listen(2) | 66 | sock.listen(2) |
| 67 | port = sock.getsockname()[1] | 67 | port = sock.getsockname()[1] |
| 68 | logger.info("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port) | 68 | self.logger.info("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port) |
| 69 | return (sock, port) | 69 | return (sock, port) |
| 70 | 70 | ||
| 71 | except socket.error: | 71 | except socket.error: |
| @@ -91,8 +91,8 @@ class QemuRunner: | |||
| 91 | def handleSIGCHLD(self, signum, frame): | 91 | def handleSIGCHLD(self, signum, frame): |
| 92 | if self.runqemu and self.runqemu.poll(): | 92 | if self.runqemu and self.runqemu.poll(): |
| 93 | if self.runqemu.returncode: | 93 | if self.runqemu.returncode: |
| 94 | logger.info('runqemu exited with code %d' % self.runqemu.returncode) | 94 | self.logger.info('runqemu exited with code %d' % self.runqemu.returncode) |
| 95 | logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout)) | 95 | self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout)) |
| 96 | self.stop() | 96 | self.stop() |
| 97 | self._dump_host() | 97 | self._dump_host() |
| 98 | raise SystemExit | 98 | raise SystemExit |
| @@ -105,15 +105,15 @@ class QemuRunner: | |||
| 105 | # interact badly with screensavers. | 105 | # interact badly with screensavers. |
| 106 | env["QEMU_DONT_GRAB"] = "1" | 106 | env["QEMU_DONT_GRAB"] = "1" |
| 107 | if not os.path.exists(self.rootfs): | 107 | if not os.path.exists(self.rootfs): |
| 108 | logger.error("Invalid rootfs %s" % self.rootfs) | 108 | self.logger.error("Invalid rootfs %s" % self.rootfs) |
| 109 | return False | 109 | return False |
| 110 | if not os.path.exists(self.tmpdir): | 110 | if not os.path.exists(self.tmpdir): |
| 111 | logger.error("Invalid TMPDIR path %s" % self.tmpdir) | 111 | self.logger.error("Invalid TMPDIR path %s" % self.tmpdir) |
| 112 | return False | 112 | return False |
| 113 | else: | 113 | else: |
| 114 | env["OE_TMPDIR"] = self.tmpdir | 114 | env["OE_TMPDIR"] = self.tmpdir |
| 115 | if not os.path.exists(self.deploy_dir_image): | 115 | if not os.path.exists(self.deploy_dir_image): |
| 116 | logger.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image) | 116 | self.logger.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image) |
| 117 | return False | 117 | return False |
| 118 | else: | 118 | else: |
| 119 | env["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image | 119 | env["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image |
| @@ -121,10 +121,10 @@ class QemuRunner: | |||
| 121 | if not launch_cmd: | 121 | if not launch_cmd: |
| 122 | launch_cmd = 'runqemu %s %s ' % ('snapshot' if discard_writes else '', runqemuparams) | 122 | launch_cmd = 'runqemu %s %s ' % ('snapshot' if discard_writes else '', runqemuparams) |
| 123 | if self.use_kvm: | 123 | if self.use_kvm: |
| 124 | logger.info('Using kvm for runqemu') | 124 | self.logger.info('Using kvm for runqemu') |
| 125 | launch_cmd += ' kvm' | 125 | launch_cmd += ' kvm' |
| 126 | else: | 126 | else: |
| 127 | logger.info('Not using kvm for runqemu') | 127 | self.logger.info('Not using kvm for runqemu') |
| 128 | if not self.display: | 128 | if not self.display: |
| 129 | launch_cmd += ' nographic' | 129 | launch_cmd += ' nographic' |
| 130 | launch_cmd += ' %s %s' % (self.machine, self.rootfs) | 130 | launch_cmd += ' %s %s' % (self.machine, self.rootfs) |
| @@ -136,7 +136,7 @@ class QemuRunner: | |||
| 136 | threadsock, threadport = self.create_socket() | 136 | threadsock, threadport = self.create_socket() |
| 137 | self.server_socket, self.serverport = self.create_socket() | 137 | self.server_socket, self.serverport = self.create_socket() |
| 138 | except socket.error as msg: | 138 | except socket.error as msg: |
| 139 | logger.error("Failed to create listening socket: %s" % msg[1]) | 139 | self.logger.error("Failed to create listening socket: %s" % msg[1]) |
| 140 | return False | 140 | return False |
| 141 | 141 | ||
| 142 | bootparams = 'console=tty1 console=ttyS0,115200n8 printk.time=1' | 142 | bootparams = 'console=tty1 console=ttyS0,115200n8 printk.time=1' |
| @@ -152,7 +152,7 @@ class QemuRunner: | |||
| 152 | self.origchldhandler = signal.getsignal(signal.SIGCHLD) | 152 | self.origchldhandler = signal.getsignal(signal.SIGCHLD) |
| 153 | signal.signal(signal.SIGCHLD, self.handleSIGCHLD) | 153 | signal.signal(signal.SIGCHLD, self.handleSIGCHLD) |
| 154 | 154 | ||
| 155 | logger.info('launchcmd=%s'%(launch_cmd)) | 155 | self.logger.info('launchcmd=%s'%(launch_cmd)) |
| 156 | 156 | ||
| 157 | # FIXME: We pass in stdin=subprocess.PIPE here to work around stty | 157 | # FIXME: We pass in stdin=subprocess.PIPE here to work around stty |
| 158 | # blocking at the end of the runqemu script when using this within | 158 | # blocking at the end of the runqemu script when using this within |
| @@ -187,24 +187,24 @@ class QemuRunner: | |||
| 187 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) | 187 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) |
| 188 | sys.exit(0) | 188 | sys.exit(0) |
| 189 | 189 | ||
| 190 | logger.info("runqemu started, pid is %s" % self.runqemu.pid) | 190 | self.logger.info("runqemu started, pid is %s" % self.runqemu.pid) |
| 191 | logger.info("waiting at most %s seconds for qemu pid" % self.runqemutime) | 191 | self.logger.info("waiting at most %s seconds for qemu pid" % self.runqemutime) |
| 192 | endtime = time.time() + self.runqemutime | 192 | endtime = time.time() + self.runqemutime |
| 193 | while not self.is_alive() and time.time() < endtime: | 193 | while not self.is_alive() and time.time() < endtime: |
| 194 | if self.runqemu.poll(): | 194 | if self.runqemu.poll(): |
| 195 | if self.runqemu.returncode: | 195 | if self.runqemu.returncode: |
| 196 | # No point waiting any longer | 196 | # No point waiting any longer |
| 197 | logger.info('runqemu exited with code %d' % self.runqemu.returncode) | 197 | self.logger.info('runqemu exited with code %d' % self.runqemu.returncode) |
| 198 | self._dump_host() | 198 | self._dump_host() |
| 199 | self.stop() | 199 | self.stop() |
| 200 | logger.info("Output from runqemu:\n%s" % self.getOutput(output)) | 200 | self.logger.info("Output from runqemu:\n%s" % self.getOutput(output)) |
| 201 | return False | 201 | return False |
| 202 | time.sleep(1) | 202 | time.sleep(1) |
| 203 | 203 | ||
| 204 | out = self.getOutput(output) | 204 | out = self.getOutput(output) |
| 205 | netconf = False # network configuration is not required by default | 205 | netconf = False # network configuration is not required by default |
| 206 | if self.is_alive(): | 206 | if self.is_alive(): |
| 207 | logger.info("qemu started in %s seconds - qemu procces pid is %s" % (time.time() - (endtime - self.runqemutime), self.qemupid)) | 207 | self.logger.info("qemu started in %s seconds - qemu procces pid is %s" % (time.time() - (endtime - self.runqemutime), self.qemupid)) |
| 208 | if get_ip: | 208 | if get_ip: |
| 209 | cmdline = '' | 209 | cmdline = '' |
| 210 | with open('/proc/%s/cmdline' % self.qemupid) as p: | 210 | with open('/proc/%s/cmdline' % self.qemupid) as p: |
| @@ -216,7 +216,7 @@ class QemuRunner: | |||
| 216 | ips = re.findall("((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1]) | 216 | ips = re.findall("((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1]) |
| 217 | self.ip = ips[0] | 217 | self.ip = ips[0] |
| 218 | self.server_ip = ips[1] | 218 | self.server_ip = ips[1] |
| 219 | logger.info("qemu cmdline used:\n{}".format(cmdline)) | 219 | self.logger.info("qemu cmdline used:\n{}".format(cmdline)) |
| 220 | except (IndexError, ValueError): | 220 | except (IndexError, ValueError): |
| 221 | # Try to get network configuration from runqemu output | 221 | # Try to get network configuration from runqemu output |
| 222 | match = re.match('.*Network configuration: ([0-9.]+)::([0-9.]+):([0-9.]+)$.*', | 222 | match = re.match('.*Network configuration: ([0-9.]+)::([0-9.]+):([0-9.]+)$.*', |
| @@ -228,27 +228,27 @@ class QemuRunner: | |||
| 228 | # and guest networking is not configured | 228 | # and guest networking is not configured |
| 229 | netconf = True | 229 | netconf = True |
| 230 | else: | 230 | else: |
| 231 | logger.error("Couldn't get ip from qemu command line and runqemu output! " | 231 | self.logger.error("Couldn't get ip from qemu command line and runqemu output! " |
| 232 | "Here is the qemu command line used:\n%s\n" | 232 | "Here is the qemu command line used:\n%s\n" |
| 233 | "and output from runqemu:\n%s" % (cmdline, out)) | 233 | "and output from runqemu:\n%s" % (cmdline, out)) |
| 234 | self._dump_host() | 234 | self._dump_host() |
| 235 | self.stop() | 235 | self.stop() |
| 236 | return False | 236 | return False |
| 237 | 237 | ||
| 238 | logger.info("Target IP: %s" % self.ip) | 238 | self.logger.info("Target IP: %s" % self.ip) |
| 239 | logger.info("Server IP: %s" % self.server_ip) | 239 | self.logger.info("Server IP: %s" % self.server_ip) |
| 240 | 240 | ||
| 241 | self.thread = LoggingThread(self.log, threadsock, logger) | 241 | self.thread = LoggingThread(self.log, threadsock, self.logger) |
| 242 | self.thread.start() | 242 | self.thread.start() |
| 243 | if not self.thread.connection_established.wait(self.boottime): | 243 | if not self.thread.connection_established.wait(self.boottime): |
| 244 | logger.error("Didn't receive a console connection from qemu. " | 244 | self.logger.error("Didn't receive a console connection from qemu. " |
| 245 | "Here is the qemu command line used:\n%s\nand " | 245 | "Here is the qemu command line used:\n%s\nand " |
| 246 | "output from runqemu:\n%s" % (cmdline, out)) | 246 | "output from runqemu:\n%s" % (cmdline, out)) |
| 247 | self.stop_thread() | 247 | self.stop_thread() |
| 248 | return False | 248 | return False |
| 249 | 249 | ||
| 250 | logger.info("Output from runqemu:\n%s", out) | 250 | self.logger.info("Output from runqemu:\n%s", out) |
| 251 | logger.info("Waiting at most %d seconds for login banner" % self.boottime) | 251 | self.logger.info("Waiting at most %d seconds for login banner" % self.boottime) |
| 252 | endtime = time.time() + self.boottime | 252 | endtime = time.time() + self.boottime |
| 253 | socklist = [self.server_socket] | 253 | socklist = [self.server_socket] |
| 254 | reachedlogin = False | 254 | reachedlogin = False |
| @@ -267,7 +267,7 @@ class QemuRunner: | |||
| 267 | qemusock.setblocking(0) | 267 | qemusock.setblocking(0) |
| 268 | socklist.append(qemusock) | 268 | socklist.append(qemusock) |
| 269 | socklist.remove(self.server_socket) | 269 | socklist.remove(self.server_socket) |
| 270 | logger.info("Connection from %s:%s" % addr) | 270 | self.logger.info("Connection from %s:%s" % addr) |
| 271 | else: | 271 | else: |
| 272 | data = data + sock.recv(1024) | 272 | data = data + sock.recv(1024) |
| 273 | if data: | 273 | if data: |
| @@ -279,7 +279,7 @@ class QemuRunner: | |||
| 279 | self.server_socket = qemusock | 279 | self.server_socket = qemusock |
| 280 | stopread = True | 280 | stopread = True |
| 281 | reachedlogin = True | 281 | reachedlogin = True |
| 282 | logger.info("Reached login banner") | 282 | self.logger.info("Reached login banner") |
| 283 | except UnicodeDecodeError: | 283 | except UnicodeDecodeError: |
| 284 | continue | 284 | continue |
| 285 | else: | 285 | else: |
| @@ -288,10 +288,10 @@ class QemuRunner: | |||
| 288 | stopread = True | 288 | stopread = True |
| 289 | 289 | ||
| 290 | if not reachedlogin: | 290 | if not reachedlogin: |
| 291 | logger.info("Target didn't reached login boot in %d seconds" % self.boottime) | 291 | self.logger.info("Target didn't reached login boot in %d seconds" % self.boottime) |
| 292 | lines = "\n".join(bootlog.splitlines()[-25:]) | 292 | lines = "\n".join(bootlog.splitlines()[-25:]) |
| 293 | logger.info("Last 25 lines of text:\n%s" % lines) | 293 | self.logger.info("Last 25 lines of text:\n%s" % lines) |
| 294 | logger.info("Check full boot log: %s" % self.logfile) | 294 | self.logger.info("Check full boot log: %s" % self.logfile) |
| 295 | self._dump_host() | 295 | self._dump_host() |
| 296 | self.stop() | 296 | self.stop() |
| 297 | return False | 297 | return False |
| @@ -301,30 +301,30 @@ class QemuRunner: | |||
| 301 | (status, output) = self.run_serial("root\n", raw=True) | 301 | (status, output) = self.run_serial("root\n", raw=True) |
| 302 | if re.search("root@[a-zA-Z0-9\-]+:~#", output): | 302 | if re.search("root@[a-zA-Z0-9\-]+:~#", output): |
| 303 | self.logged = True | 303 | self.logged = True |
| 304 | logger.info("Logged as root in serial console") | 304 | self.logger.info("Logged as root in serial console") |
| 305 | if netconf: | 305 | if netconf: |
| 306 | # configure guest networking | 306 | # configure guest networking |
| 307 | cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask) | 307 | cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask) |
| 308 | output = self.run_serial(cmd, raw=True)[1] | 308 | output = self.run_serial(cmd, raw=True)[1] |
| 309 | if re.search("root@[a-zA-Z0-9\-]+:~#", output): | 309 | if re.search("root@[a-zA-Z0-9\-]+:~#", output): |
| 310 | logger.info("configured ip address %s", self.ip) | 310 | self.logger.info("configured ip address %s", self.ip) |
| 311 | else: | 311 | else: |
| 312 | logger.info("Couldn't configure guest networking") | 312 | self.logger.info("Couldn't configure guest networking") |
| 313 | else: | 313 | else: |
| 314 | logger.info("Couldn't login into serial console" | 314 | self.logger.info("Couldn't login into serial console" |
| 315 | " as root using blank password") | 315 | " as root using blank password") |
| 316 | except: | 316 | except: |
| 317 | logger.info("Serial console failed while trying to login") | 317 | self.logger.info("Serial console failed while trying to login") |
| 318 | 318 | ||
| 319 | else: | 319 | else: |
| 320 | logger.error("Qemu pid didn't appear in %s seconds" % self.runqemutime) | 320 | self.logger.error("Qemu pid didn't appear in %s seconds" % self.runqemutime) |
| 321 | self._dump_host() | 321 | self._dump_host() |
| 322 | self.stop() | 322 | self.stop() |
| 323 | op = self.getOutput(output) | 323 | op = self.getOutput(output) |
| 324 | if op: | 324 | if op: |
| 325 | logger.error("Output from runqemu:\n%s" % op) | 325 | self.logger.error("Output from runqemu:\n%s" % op) |
| 326 | else: | 326 | else: |
| 327 | logger.error("No output from runqemu.\n") | 327 | self.logger.error("No output from runqemu.\n") |
| 328 | return False | 328 | return False |
| 329 | 329 | ||
| 330 | return self.is_alive() | 330 | return self.is_alive() |
| @@ -337,7 +337,7 @@ class QemuRunner: | |||
| 337 | if self.runqemu: | 337 | if self.runqemu: |
| 338 | if hasattr(self, "monitorpid"): | 338 | if hasattr(self, "monitorpid"): |
| 339 | os.kill(self.monitorpid, signal.SIGKILL) | 339 | os.kill(self.monitorpid, signal.SIGKILL) |
| 340 | logger.info("Sending SIGTERM to runqemu") | 340 | self.logger.info("Sending SIGTERM to runqemu") |
| 341 | try: | 341 | try: |
| 342 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) | 342 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) |
| 343 | except OSError as e: | 343 | except OSError as e: |
| @@ -347,7 +347,7 @@ class QemuRunner: | |||
| 347 | while self.runqemu.poll() is None and time.time() < endtime: | 347 | while self.runqemu.poll() is None and time.time() < endtime: |
| 348 | time.sleep(1) | 348 | time.sleep(1) |
| 349 | if self.runqemu.poll() is None: | 349 | if self.runqemu.poll() is None: |
| 350 | logger.info("Sending SIGKILL to runqemu") | 350 | self.logger.info("Sending SIGKILL to runqemu") |
| 351 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL) | 351 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL) |
| 352 | self.runqemu = None | 352 | self.runqemu = None |
| 353 | if hasattr(self, 'server_socket') and self.server_socket: | 353 | if hasattr(self, 'server_socket') and self.server_socket: |
| @@ -362,7 +362,7 @@ class QemuRunner: | |||
| 362 | # qemu-system behaves well and a SIGTERM is enough | 362 | # qemu-system behaves well and a SIGTERM is enough |
| 363 | os.kill(self.qemupid, signal.SIGTERM) | 363 | os.kill(self.qemupid, signal.SIGTERM) |
| 364 | except ProcessLookupError as e: | 364 | except ProcessLookupError as e: |
| 365 | logger.warn('qemu-system ended unexpectedly') | 365 | self.logger.warn('qemu-system ended unexpectedly') |
| 366 | 366 | ||
| 367 | def stop_thread(self): | 367 | def stop_thread(self): |
| 368 | if self.thread and self.thread.is_alive(): | 368 | if self.thread and self.thread.is_alive(): |
| @@ -370,7 +370,7 @@ class QemuRunner: | |||
| 370 | self.thread.join() | 370 | self.thread.join() |
| 371 | 371 | ||
| 372 | def restart(self, qemuparams = None): | 372 | def restart(self, qemuparams = None): |
| 373 | logger.info("Restarting qemu process") | 373 | self.logger.info("Restarting qemu process") |
| 374 | if self.runqemu.poll() is None: | 374 | if self.runqemu.poll() is None: |
| 375 | self.stop() | 375 | self.stop() |
| 376 | if self.start(qemuparams): | 376 | if self.start(qemuparams): |
| @@ -479,7 +479,7 @@ class QemuRunner: | |||
| 479 | 479 | ||
| 480 | def _dump_host(self): | 480 | def _dump_host(self): |
| 481 | self.host_dumper.create_dir("qemu") | 481 | self.host_dumper.create_dir("qemu") |
| 482 | logger.warn("Qemu ended unexpectedly, dump data from host" | 482 | self.logger.warn("Qemu ended unexpectedly, dump data from host" |
| 483 | " is in %s" % self.host_dumper.dump_dir) | 483 | " is in %s" % self.host_dumper.dump_dir) |
| 484 | self.host_dumper.dump_host() | 484 | self.host_dumper.dump_host() |
| 485 | 485 | ||
