diff options
-rw-r--r-- | meta/lib/oeqa/utils/qemurunner.py | 74 |
1 files changed, 37 insertions, 37 deletions
diff --git a/meta/lib/oeqa/utils/qemurunner.py b/meta/lib/oeqa/utils/qemurunner.py index aa2600b827..32148871ff 100644 --- a/meta/lib/oeqa/utils/qemurunner.py +++ b/meta/lib/oeqa/utils/qemurunner.py | |||
@@ -68,7 +68,7 @@ class QemuRunner: | |||
68 | sock.bind(("127.0.0.1",0)) | 68 | sock.bind(("127.0.0.1",0)) |
69 | sock.listen(2) | 69 | sock.listen(2) |
70 | port = sock.getsockname()[1] | 70 | port = sock.getsockname()[1] |
71 | self.logger.info("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port) | 71 | self.logger.debug("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port) |
72 | return (sock, port) | 72 | return (sock, port) |
73 | 73 | ||
74 | except socket.error: | 74 | except socket.error: |
@@ -95,8 +95,8 @@ class QemuRunner: | |||
95 | def handleSIGCHLD(self, signum, frame): | 95 | def handleSIGCHLD(self, signum, frame): |
96 | if self.runqemu and self.runqemu.poll(): | 96 | if self.runqemu and self.runqemu.poll(): |
97 | if self.runqemu.returncode: | 97 | if self.runqemu.returncode: |
98 | self.logger.info('runqemu exited with code %d' % self.runqemu.returncode) | 98 | self.logger.debug('runqemu exited with code %d' % self.runqemu.returncode) |
99 | self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout)) | 99 | self.logger.debug("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout)) |
100 | self.stop() | 100 | self.stop() |
101 | self._dump_host() | 101 | self._dump_host() |
102 | raise SystemExit | 102 | raise SystemExit |
@@ -125,10 +125,10 @@ class QemuRunner: | |||
125 | if not launch_cmd: | 125 | if not launch_cmd: |
126 | launch_cmd = 'runqemu %s %s ' % ('snapshot' if discard_writes else '', runqemuparams) | 126 | launch_cmd = 'runqemu %s %s ' % ('snapshot' if discard_writes else '', runqemuparams) |
127 | if self.use_kvm: | 127 | if self.use_kvm: |
128 | self.logger.info('Using kvm for runqemu') | 128 | self.logger.debug('Using kvm for runqemu') |
129 | launch_cmd += ' kvm' | 129 | launch_cmd += ' kvm' |
130 | else: | 130 | else: |
131 | self.logger.info('Not using kvm for runqemu') | 131 | self.logger.debug('Not using kvm for runqemu') |
132 | if not self.display: | 132 | if not self.display: |
133 | launch_cmd += ' nographic' | 133 | launch_cmd += ' nographic' |
134 | launch_cmd += ' %s %s' % (self.machine, self.rootfs) | 134 | launch_cmd += ' %s %s' % (self.machine, self.rootfs) |
@@ -160,7 +160,7 @@ class QemuRunner: | |||
160 | self.origchldhandler = signal.getsignal(signal.SIGCHLD) | 160 | self.origchldhandler = signal.getsignal(signal.SIGCHLD) |
161 | signal.signal(signal.SIGCHLD, self.handleSIGCHLD) | 161 | signal.signal(signal.SIGCHLD, self.handleSIGCHLD) |
162 | 162 | ||
163 | self.logger.info('launchcmd=%s'%(launch_cmd)) | 163 | self.logger.debug('launchcmd=%s'%(launch_cmd)) |
164 | 164 | ||
165 | # FIXME: We pass in stdin=subprocess.PIPE here to work around stty | 165 | # FIXME: We pass in stdin=subprocess.PIPE here to work around stty |
166 | # blocking at the end of the runqemu script when using this within | 166 | # blocking at the end of the runqemu script when using this within |
@@ -195,17 +195,17 @@ class QemuRunner: | |||
195 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) | 195 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) |
196 | sys.exit(0) | 196 | sys.exit(0) |
197 | 197 | ||
198 | self.logger.info("runqemu started, pid is %s" % self.runqemu.pid) | 198 | self.logger.debug("runqemu started, pid is %s" % self.runqemu.pid) |
199 | self.logger.info("waiting at most %s seconds for qemu pid" % self.runqemutime) | 199 | self.logger.debug("waiting at most %s seconds for qemu pid" % self.runqemutime) |
200 | endtime = time.time() + self.runqemutime | 200 | endtime = time.time() + self.runqemutime |
201 | while not self.is_alive() and time.time() < endtime: | 201 | while not self.is_alive() and time.time() < endtime: |
202 | if self.runqemu.poll(): | 202 | if self.runqemu.poll(): |
203 | if self.runqemu.returncode: | 203 | if self.runqemu.returncode: |
204 | # No point waiting any longer | 204 | # No point waiting any longer |
205 | self.logger.info('runqemu exited with code %d' % self.runqemu.returncode) | 205 | self.logger.debug('runqemu exited with code %d' % self.runqemu.returncode) |
206 | self._dump_host() | 206 | self._dump_host() |
207 | self.stop() | 207 | self.stop() |
208 | self.logger.info("Output from runqemu:\n%s" % self.getOutput(output)) | 208 | self.logger.debug("Output from runqemu:\n%s" % self.getOutput(output)) |
209 | return False | 209 | return False |
210 | time.sleep(0.5) | 210 | time.sleep(0.5) |
211 | 211 | ||
@@ -214,7 +214,7 @@ class QemuRunner: | |||
214 | # Dump all processes to help us to figure out what is going on... | 214 | # Dump all processes to help us to figure out what is going on... |
215 | ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,command '], stdout=subprocess.PIPE).communicate()[0] | 215 | ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,command '], stdout=subprocess.PIPE).communicate()[0] |
216 | processes = ps.decode("utf-8") | 216 | processes = ps.decode("utf-8") |
217 | self.logger.info("Running processes:\n%s" % processes) | 217 | self.logger.debug("Running processes:\n%s" % processes) |
218 | self._dump_host() | 218 | self._dump_host() |
219 | self.stop() | 219 | self.stop() |
220 | op = self.getOutput(output) | 220 | op = self.getOutput(output) |
@@ -227,7 +227,7 @@ class QemuRunner: | |||
227 | # We are alive: qemu is running | 227 | # We are alive: qemu is running |
228 | out = self.getOutput(output) | 228 | out = self.getOutput(output) |
229 | netconf = False # network configuration is not required by default | 229 | netconf = False # network configuration is not required by default |
230 | self.logger.info("qemu started in %s seconds - qemu procces pid is %s" % (time.time() - (endtime - self.runqemutime), self.qemupid)) | 230 | self.logger.debug("qemu started in %s seconds - qemu procces pid is %s" % (time.time() - (endtime - self.runqemutime), self.qemupid)) |
231 | if get_ip: | 231 | if get_ip: |
232 | cmdline = '' | 232 | cmdline = '' |
233 | with open('/proc/%s/cmdline' % self.qemupid) as p: | 233 | with open('/proc/%s/cmdline' % self.qemupid) as p: |
@@ -239,7 +239,7 @@ class QemuRunner: | |||
239 | ips = re.findall("((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1]) | 239 | ips = re.findall("((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1]) |
240 | self.ip = ips[0] | 240 | self.ip = ips[0] |
241 | self.server_ip = ips[1] | 241 | self.server_ip = ips[1] |
242 | self.logger.info("qemu cmdline used:\n{}".format(cmdline)) | 242 | self.logger.debug("qemu cmdline used:\n{}".format(cmdline)) |
243 | except (IndexError, ValueError): | 243 | except (IndexError, ValueError): |
244 | # Try to get network configuration from runqemu output | 244 | # Try to get network configuration from runqemu output |
245 | match = re.match('.*Network configuration: ([0-9.]+)::([0-9.]+):([0-9.]+)$.*', | 245 | match = re.match('.*Network configuration: ([0-9.]+)::([0-9.]+):([0-9.]+)$.*', |
@@ -258,8 +258,8 @@ class QemuRunner: | |||
258 | self.stop() | 258 | self.stop() |
259 | return False | 259 | return False |
260 | 260 | ||
261 | self.logger.info("Target IP: %s" % self.ip) | 261 | self.logger.debug("Target IP: %s" % self.ip) |
262 | self.logger.info("Server IP: %s" % self.server_ip) | 262 | self.logger.debug("Server IP: %s" % self.server_ip) |
263 | 263 | ||
264 | self.thread = LoggingThread(self.log, threadsock, self.logger) | 264 | self.thread = LoggingThread(self.log, threadsock, self.logger) |
265 | self.thread.start() | 265 | self.thread.start() |
@@ -270,8 +270,8 @@ class QemuRunner: | |||
270 | self.stop_thread() | 270 | self.stop_thread() |
271 | return False | 271 | return False |
272 | 272 | ||
273 | self.logger.info("Output from runqemu:\n%s", out) | 273 | self.logger.debug("Output from runqemu:\n%s", out) |
274 | self.logger.info("Waiting at most %d seconds for login banner" % self.boottime) | 274 | self.logger.debug("Waiting at most %d seconds for login banner" % self.boottime) |
275 | endtime = time.time() + self.boottime | 275 | endtime = time.time() + self.boottime |
276 | socklist = [self.server_socket] | 276 | socklist = [self.server_socket] |
277 | reachedlogin = False | 277 | reachedlogin = False |
@@ -290,7 +290,7 @@ class QemuRunner: | |||
290 | qemusock.setblocking(0) | 290 | qemusock.setblocking(0) |
291 | socklist.append(qemusock) | 291 | socklist.append(qemusock) |
292 | socklist.remove(self.server_socket) | 292 | socklist.remove(self.server_socket) |
293 | self.logger.info("Connection from %s:%s" % addr) | 293 | self.logger.debug("Connection from %s:%s" % addr) |
294 | else: | 294 | else: |
295 | data = data + sock.recv(1024) | 295 | data = data + sock.recv(1024) |
296 | if data: | 296 | if data: |
@@ -302,7 +302,7 @@ class QemuRunner: | |||
302 | self.server_socket = qemusock | 302 | self.server_socket = qemusock |
303 | stopread = True | 303 | stopread = True |
304 | reachedlogin = True | 304 | reachedlogin = True |
305 | self.logger.info("Reached login banner") | 305 | self.logger.debug("Reached login banner") |
306 | except UnicodeDecodeError: | 306 | except UnicodeDecodeError: |
307 | continue | 307 | continue |
308 | else: | 308 | else: |
@@ -312,12 +312,12 @@ class QemuRunner: | |||
312 | 312 | ||
313 | 313 | ||
314 | if not reachedlogin: | 314 | if not reachedlogin: |
315 | self.logger.info("Target didn't reached login boot in %d seconds" % self.boottime) | 315 | self.logger.debug("Target didn't reached login boot in %d seconds" % self.boottime) |
316 | tail = lambda l: "\n".join(l.splitlines()[-25:]) | 316 | tail = lambda l: "\n".join(l.splitlines()[-25:]) |
317 | # in case bootlog is empty, use tail qemu log store at self.msg | 317 | # in case bootlog is empty, use tail qemu log store at self.msg |
318 | lines = tail(bootlog if bootlog else self.msg) | 318 | lines = tail(bootlog if bootlog else self.msg) |
319 | self.logger.info("Last 25 lines of text:\n%s" % lines) | 319 | self.logger.debug("Last 25 lines of text:\n%s" % lines) |
320 | self.logger.info("Check full boot log: %s" % self.logfile) | 320 | self.logger.debug("Check full boot log: %s" % self.logfile) |
321 | self._dump_host() | 321 | self._dump_host() |
322 | self.stop() | 322 | self.stop() |
323 | return False | 323 | return False |
@@ -327,20 +327,20 @@ class QemuRunner: | |||
327 | (status, output) = self.run_serial("root\n", raw=True) | 327 | (status, output) = self.run_serial("root\n", raw=True) |
328 | if re.search("root@[a-zA-Z0-9\-]+:~#", output): | 328 | if re.search("root@[a-zA-Z0-9\-]+:~#", output): |
329 | self.logged = True | 329 | self.logged = True |
330 | self.logger.info("Logged as root in serial console") | 330 | self.logger.debug("Logged as root in serial console") |
331 | if netconf: | 331 | if netconf: |
332 | # configure guest networking | 332 | # configure guest networking |
333 | cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask) | 333 | cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask) |
334 | output = self.run_serial(cmd, raw=True)[1] | 334 | output = self.run_serial(cmd, raw=True)[1] |
335 | if re.search("root@[a-zA-Z0-9\-]+:~#", output): | 335 | if re.search("root@[a-zA-Z0-9\-]+:~#", output): |
336 | self.logger.info("configured ip address %s", self.ip) | 336 | self.logger.debug("configured ip address %s", self.ip) |
337 | else: | 337 | else: |
338 | self.logger.info("Couldn't configure guest networking") | 338 | self.logger.debug("Couldn't configure guest networking") |
339 | else: | 339 | else: |
340 | self.logger.info("Couldn't login into serial console" | 340 | self.logger.debug("Couldn't login into serial console" |
341 | " as root using blank password") | 341 | " as root using blank password") |
342 | except: | 342 | except: |
343 | self.logger.info("Serial console failed while trying to login") | 343 | self.logger.debug("Serial console failed while trying to login") |
344 | return True | 344 | return True |
345 | 345 | ||
346 | def stop(self): | 346 | def stop(self): |
@@ -351,7 +351,7 @@ class QemuRunner: | |||
351 | if self.runqemu: | 351 | if self.runqemu: |
352 | if hasattr(self, "monitorpid"): | 352 | if hasattr(self, "monitorpid"): |
353 | os.kill(self.monitorpid, signal.SIGKILL) | 353 | os.kill(self.monitorpid, signal.SIGKILL) |
354 | self.logger.info("Sending SIGTERM to runqemu") | 354 | self.logger.debug("Sending SIGTERM to runqemu") |
355 | try: | 355 | try: |
356 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) | 356 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) |
357 | except OSError as e: | 357 | except OSError as e: |
@@ -361,7 +361,7 @@ class QemuRunner: | |||
361 | while self.runqemu.poll() is None and time.time() < endtime: | 361 | while self.runqemu.poll() is None and time.time() < endtime: |
362 | time.sleep(1) | 362 | time.sleep(1) |
363 | if self.runqemu.poll() is None: | 363 | if self.runqemu.poll() is None: |
364 | self.logger.info("Sending SIGKILL to runqemu") | 364 | self.logger.debug("Sending SIGKILL to runqemu") |
365 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL) | 365 | os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL) |
366 | self.runqemu = None | 366 | self.runqemu = None |
367 | if hasattr(self, 'server_socket') and self.server_socket: | 367 | if hasattr(self, 'server_socket') and self.server_socket: |
@@ -387,7 +387,7 @@ class QemuRunner: | |||
387 | self.thread.join() | 387 | self.thread.join() |
388 | 388 | ||
389 | def restart(self, qemuparams = None): | 389 | def restart(self, qemuparams = None): |
390 | self.logger.info("Restarting qemu process") | 390 | self.logger.debug("Restarting qemu process") |
391 | if self.runqemu.poll() is None: | 391 | if self.runqemu.poll() is None: |
392 | self.stop() | 392 | self.stop() |
393 | if self.start(qemuparams): | 393 | if self.start(qemuparams): |
@@ -485,17 +485,17 @@ class LoggingThread(threading.Thread): | |||
485 | self.teardown() | 485 | self.teardown() |
486 | 486 | ||
487 | def run(self): | 487 | def run(self): |
488 | self.logger.info("Starting logging thread") | 488 | self.logger.debug("Starting logging thread") |
489 | self.readpipe, self.writepipe = os.pipe() | 489 | self.readpipe, self.writepipe = os.pipe() |
490 | threading.Thread.run(self) | 490 | threading.Thread.run(self) |
491 | 491 | ||
492 | def stop(self): | 492 | def stop(self): |
493 | self.logger.info("Stopping logging thread") | 493 | self.logger.debug("Stopping logging thread") |
494 | if self.running: | 494 | if self.running: |
495 | os.write(self.writepipe, bytes("stop", "utf-8")) | 495 | os.write(self.writepipe, bytes("stop", "utf-8")) |
496 | 496 | ||
497 | def teardown(self): | 497 | def teardown(self): |
498 | self.logger.info("Tearing down logging thread") | 498 | self.logger.debug("Tearing down logging thread") |
499 | self.close_socket(self.serversock) | 499 | self.close_socket(self.serversock) |
500 | 500 | ||
501 | if self.readsock is not None: | 501 | if self.readsock is not None: |
@@ -513,7 +513,7 @@ class LoggingThread(threading.Thread): | |||
513 | 513 | ||
514 | breakout = False | 514 | breakout = False |
515 | self.running = True | 515 | self.running = True |
516 | self.logger.info("Starting thread event loop") | 516 | self.logger.debug("Starting thread event loop") |
517 | while not breakout: | 517 | while not breakout: |
518 | events = poll.poll() | 518 | events = poll.poll() |
519 | for event in events: | 519 | for event in events: |
@@ -523,19 +523,19 @@ class LoggingThread(threading.Thread): | |||
523 | 523 | ||
524 | # Event to stop the thread | 524 | # Event to stop the thread |
525 | if self.readpipe == event[0]: | 525 | if self.readpipe == event[0]: |
526 | self.logger.info("Stop event received") | 526 | self.logger.debug("Stop event received") |
527 | breakout = True | 527 | breakout = True |
528 | break | 528 | break |
529 | 529 | ||
530 | # A connection request was received | 530 | # A connection request was received |
531 | elif self.serversock.fileno() == event[0]: | 531 | elif self.serversock.fileno() == event[0]: |
532 | self.logger.info("Connection request received") | 532 | self.logger.debug("Connection request received") |
533 | self.readsock, _ = self.serversock.accept() | 533 | self.readsock, _ = self.serversock.accept() |
534 | self.readsock.setblocking(0) | 534 | self.readsock.setblocking(0) |
535 | poll.unregister(self.serversock.fileno()) | 535 | poll.unregister(self.serversock.fileno()) |
536 | poll.register(self.readsock.fileno(), event_read_mask) | 536 | poll.register(self.readsock.fileno(), event_read_mask) |
537 | 537 | ||
538 | self.logger.info("Setting connection established event") | 538 | self.logger.debug("Setting connection established event") |
539 | self.connection_established.set() | 539 | self.connection_established.set() |
540 | 540 | ||
541 | # Actual data to be logged | 541 | # Actual data to be logged |