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