summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorRichard Purdie <richard.purdie@linuxfoundation.org>2017-11-08 18:13:24 +0000
committerRichard Purdie <richard.purdie@linuxfoundation.org>2017-11-09 12:24:24 +0000
commit07cddf76a2b4e6ab3cdfe9cea2e69566070f7c88 (patch)
tree4c9273a2feeece1bded7fd3dc0857033b3125a59
parent77239864f465adbb6a589d1952bcfd43df5712bd (diff)
downloadpoky-07cddf76a2b4e6ab3cdfe9cea2e69566070f7c88.tar.gz
oeqa/qemurunner: Use logger.debug, not logger.info
Bitbake logs info messages to the console. These messages are really there as debugging information. At the debug level, they will be shown in failure logs and in the task logs but not on the console which is what we want in this case. (From OE-Core rev: e05b14ad5a3c5ac1656b6fffdcf7e58250638e96) Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
-rw-r--r--meta/lib/oeqa/utils/qemurunner.py74
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