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: 5c1cdd4f3ea59a202fff853e0390b9aa5859dc74)

(From OE-Core rev: 7274a9caa39c77128ecaf398437e685923ebc2c5)

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Signed-off-by: Armin Kuster <akuster@mvista.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Signed-off-by: Armin Kuster <akuster808@gmail.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
This commit is contained in:
Richard Purdie 2017-11-08 18:13:24 +00:00
parent 23037f8c91
commit 1659b33553
1 changed files with 37 additions and 37 deletions

View File

@ -68,7 +68,7 @@ class QemuRunner:
sock.bind(("127.0.0.1",0)) sock.bind(("127.0.0.1",0))
sock.listen(2) sock.listen(2)
port = sock.getsockname()[1] port = sock.getsockname()[1]
self.logger.info("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port) self.logger.debug("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port)
return (sock, port) return (sock, port)
except socket.error: except socket.error:
@ -95,8 +95,8 @@ class QemuRunner:
def handleSIGCHLD(self, signum, frame): def handleSIGCHLD(self, signum, frame):
if self.runqemu and self.runqemu.poll(): if self.runqemu and self.runqemu.poll():
if self.runqemu.returncode: if self.runqemu.returncode:
self.logger.info('runqemu exited with code %d' % self.runqemu.returncode) self.logger.debug('runqemu exited with code %d' % self.runqemu.returncode)
self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout)) self.logger.debug("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout))
self.stop() self.stop()
self._dump_host() self._dump_host()
raise SystemExit raise SystemExit
@ -124,10 +124,10 @@ class QemuRunner:
if not launch_cmd: if not launch_cmd:
launch_cmd = 'runqemu %s %s ' % ('snapshot' if discard_writes else '', runqemuparams) launch_cmd = 'runqemu %s %s ' % ('snapshot' if discard_writes else '', runqemuparams)
if self.use_kvm: if self.use_kvm:
self.logger.info('Using kvm for runqemu') self.logger.debug('Using kvm for runqemu')
launch_cmd += ' kvm' launch_cmd += ' kvm'
else: else:
self.logger.info('Not using kvm for runqemu') self.logger.debug('Not using kvm for runqemu')
if not self.display: if not self.display:
launch_cmd += ' nographic' launch_cmd += ' nographic'
launch_cmd += ' %s %s' % (self.machine, self.rootfs) launch_cmd += ' %s %s' % (self.machine, self.rootfs)
@ -159,7 +159,7 @@ class QemuRunner:
self.origchldhandler = signal.getsignal(signal.SIGCHLD) self.origchldhandler = signal.getsignal(signal.SIGCHLD)
signal.signal(signal.SIGCHLD, self.handleSIGCHLD) signal.signal(signal.SIGCHLD, self.handleSIGCHLD)
self.logger.info('launchcmd=%s'%(launch_cmd)) self.logger.debug('launchcmd=%s'%(launch_cmd))
# FIXME: We pass in stdin=subprocess.PIPE here to work around stty # FIXME: We pass in stdin=subprocess.PIPE here to work around stty
# blocking at the end of the runqemu script when using this within # blocking at the end of the runqemu script when using this within
@ -194,17 +194,17 @@ class QemuRunner:
os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
sys.exit(0) sys.exit(0)
self.logger.info("runqemu started, pid is %s" % self.runqemu.pid) self.logger.debug("runqemu started, pid is %s" % self.runqemu.pid)
self.logger.info("waiting at most %s seconds for qemu pid" % self.runqemutime) self.logger.debug("waiting at most %s seconds for qemu pid" % self.runqemutime)
endtime = time.time() + self.runqemutime endtime = time.time() + self.runqemutime
while not self.is_alive() and time.time() < endtime: while not self.is_alive() and time.time() < endtime:
if self.runqemu.poll(): if self.runqemu.poll():
if self.runqemu.returncode: if self.runqemu.returncode:
# No point waiting any longer # No point waiting any longer
self.logger.info('runqemu exited with code %d' % self.runqemu.returncode) self.logger.debug('runqemu exited with code %d' % self.runqemu.returncode)
self._dump_host() self._dump_host()
self.stop() self.stop()
self.logger.info("Output from runqemu:\n%s" % self.getOutput(output)) self.logger.debug("Output from runqemu:\n%s" % self.getOutput(output))
return False return False
time.sleep(0.5) time.sleep(0.5)
@ -213,7 +213,7 @@ class QemuRunner:
# Dump all processes to help us to figure out what is going on... # Dump all processes to help us to figure out what is going on...
ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,command '], stdout=subprocess.PIPE).communicate()[0] ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,command '], stdout=subprocess.PIPE).communicate()[0]
processes = ps.decode("utf-8") processes = ps.decode("utf-8")
self.logger.info("Running processes:\n%s" % processes) self.logger.debug("Running processes:\n%s" % processes)
self._dump_host() self._dump_host()
self.stop() self.stop()
op = self.getOutput(output) op = self.getOutput(output)
@ -226,7 +226,7 @@ class QemuRunner:
# We are alive: qemu is running # We are alive: qemu is running
out = self.getOutput(output) out = self.getOutput(output)
netconf = False # network configuration is not required by default netconf = False # network configuration is not required by default
self.logger.info("qemu started in %s seconds - qemu procces pid is %s" % (time.time() - (endtime - self.runqemutime), self.qemupid)) self.logger.debug("qemu started in %s seconds - qemu procces pid is %s" % (time.time() - (endtime - self.runqemutime), self.qemupid))
if get_ip: if get_ip:
cmdline = '' cmdline = ''
with open('/proc/%s/cmdline' % self.qemupid) as p: with open('/proc/%s/cmdline' % self.qemupid) as p:
@ -238,7 +238,7 @@ class QemuRunner:
ips = re.findall("((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1]) ips = re.findall("((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1])
self.ip = ips[0] self.ip = ips[0]
self.server_ip = ips[1] self.server_ip = ips[1]
self.logger.info("qemu cmdline used:\n{}".format(cmdline)) self.logger.debug("qemu cmdline used:\n{}".format(cmdline))
except (IndexError, ValueError): except (IndexError, ValueError):
# Try to get network configuration from runqemu output # Try to get network configuration from runqemu output
match = re.match('.*Network configuration: ([0-9.]+)::([0-9.]+):([0-9.]+)$.*', match = re.match('.*Network configuration: ([0-9.]+)::([0-9.]+):([0-9.]+)$.*',
@ -257,8 +257,8 @@ class QemuRunner:
self.stop() self.stop()
return False return False
self.logger.info("Target IP: %s" % self.ip) self.logger.debug("Target IP: %s" % self.ip)
self.logger.info("Server IP: %s" % self.server_ip) self.logger.debug("Server IP: %s" % self.server_ip)
self.thread = LoggingThread(self.log, threadsock, self.logger) self.thread = LoggingThread(self.log, threadsock, self.logger)
self.thread.start() self.thread.start()
@ -269,8 +269,8 @@ class QemuRunner:
self.stop_thread() self.stop_thread()
return False return False
self.logger.info("Output from runqemu:\n%s", out) self.logger.debug("Output from runqemu:\n%s", out)
self.logger.info("Waiting at most %d seconds for login banner" % self.boottime) self.logger.debug("Waiting at most %d seconds for login banner" % self.boottime)
endtime = time.time() + self.boottime endtime = time.time() + self.boottime
socklist = [self.server_socket] socklist = [self.server_socket]
reachedlogin = False reachedlogin = False
@ -289,7 +289,7 @@ class QemuRunner:
qemusock.setblocking(0) qemusock.setblocking(0)
socklist.append(qemusock) socklist.append(qemusock)
socklist.remove(self.server_socket) socklist.remove(self.server_socket)
self.logger.info("Connection from %s:%s" % addr) self.logger.debug("Connection from %s:%s" % addr)
else: else:
data = data + sock.recv(1024) data = data + sock.recv(1024)
if data: if data:
@ -301,7 +301,7 @@ class QemuRunner:
self.server_socket = qemusock self.server_socket = qemusock
stopread = True stopread = True
reachedlogin = True reachedlogin = True
self.logger.info("Reached login banner") self.logger.debug("Reached login banner")
except UnicodeDecodeError: except UnicodeDecodeError:
continue continue
else: else:
@ -311,12 +311,12 @@ class QemuRunner:
if not reachedlogin: if not reachedlogin:
self.logger.info("Target didn't reached login boot in %d seconds" % self.boottime) self.logger.debug("Target didn't reached login boot in %d seconds" % self.boottime)
tail = lambda l: "\n".join(l.splitlines()[-25:]) tail = lambda l: "\n".join(l.splitlines()[-25:])
# in case bootlog is empty, use tail qemu log store at self.msg # in case bootlog is empty, use tail qemu log store at self.msg
lines = tail(bootlog if bootlog else self.msg) lines = tail(bootlog if bootlog else self.msg)
self.logger.info("Last 25 lines of text:\n%s" % lines) self.logger.debug("Last 25 lines of text:\n%s" % lines)
self.logger.info("Check full boot log: %s" % self.logfile) self.logger.debug("Check full boot log: %s" % self.logfile)
self._dump_host() self._dump_host()
self.stop() self.stop()
return False return False
@ -326,20 +326,20 @@ class QemuRunner:
(status, output) = self.run_serial("root\n", raw=True) (status, output) = self.run_serial("root\n", raw=True)
if re.search("root@[a-zA-Z0-9\-]+:~#", output): if re.search("root@[a-zA-Z0-9\-]+:~#", output):
self.logged = True self.logged = True
self.logger.info("Logged as root in serial console") self.logger.debug("Logged as root in serial console")
if netconf: if netconf:
# configure guest networking # configure guest networking
cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask) cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask)
output = self.run_serial(cmd, raw=True)[1] output = self.run_serial(cmd, raw=True)[1]
if re.search("root@[a-zA-Z0-9\-]+:~#", output): if re.search("root@[a-zA-Z0-9\-]+:~#", output):
self.logger.info("configured ip address %s", self.ip) self.logger.debug("configured ip address %s", self.ip)
else: else:
self.logger.info("Couldn't configure guest networking") self.logger.debug("Couldn't configure guest networking")
else: else:
self.logger.info("Couldn't login into serial console" self.logger.debug("Couldn't login into serial console"
" as root using blank password") " as root using blank password")
except: except:
self.logger.info("Serial console failed while trying to login") self.logger.debug("Serial console failed while trying to login")
return True return True
def stop(self): def stop(self):
@ -350,7 +350,7 @@ class QemuRunner:
if self.runqemu: if self.runqemu:
if hasattr(self, "monitorpid"): if hasattr(self, "monitorpid"):
os.kill(self.monitorpid, signal.SIGKILL) os.kill(self.monitorpid, signal.SIGKILL)
self.logger.info("Sending SIGTERM to runqemu") self.logger.debug("Sending SIGTERM to runqemu")
try: try:
os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM) os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
except OSError as e: except OSError as e:
@ -360,7 +360,7 @@ class QemuRunner:
while self.runqemu.poll() is None and time.time() < endtime: while self.runqemu.poll() is None and time.time() < endtime:
time.sleep(1) time.sleep(1)
if self.runqemu.poll() is None: if self.runqemu.poll() is None:
self.logger.info("Sending SIGKILL to runqemu") self.logger.debug("Sending SIGKILL to runqemu")
os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL) os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL)
self.runqemu = None self.runqemu = None
if hasattr(self, 'server_socket') and self.server_socket: if hasattr(self, 'server_socket') and self.server_socket:
@ -386,7 +386,7 @@ class QemuRunner:
self.thread.join() self.thread.join()
def restart(self, qemuparams = None): def restart(self, qemuparams = None):
self.logger.info("Restarting qemu process") self.logger.debug("Restarting qemu process")
if self.runqemu.poll() is None: if self.runqemu.poll() is None:
self.stop() self.stop()
if self.start(qemuparams): if self.start(qemuparams):
@ -484,17 +484,17 @@ class LoggingThread(threading.Thread):
self.teardown() self.teardown()
def run(self): def run(self):
self.logger.info("Starting logging thread") self.logger.debug("Starting logging thread")
self.readpipe, self.writepipe = os.pipe() self.readpipe, self.writepipe = os.pipe()
threading.Thread.run(self) threading.Thread.run(self)
def stop(self): def stop(self):
self.logger.info("Stopping logging thread") self.logger.debug("Stopping logging thread")
if self.running: if self.running:
os.write(self.writepipe, bytes("stop", "utf-8")) os.write(self.writepipe, bytes("stop", "utf-8"))
def teardown(self): def teardown(self):
self.logger.info("Tearing down logging thread") self.logger.debug("Tearing down logging thread")
self.close_socket(self.serversock) self.close_socket(self.serversock)
if self.readsock is not None: if self.readsock is not None:
@ -512,7 +512,7 @@ class LoggingThread(threading.Thread):
breakout = False breakout = False
self.running = True self.running = True
self.logger.info("Starting thread event loop") self.logger.debug("Starting thread event loop")
while not breakout: while not breakout:
events = poll.poll() events = poll.poll()
for event in events: for event in events:
@ -522,19 +522,19 @@ class LoggingThread(threading.Thread):
# Event to stop the thread # Event to stop the thread
if self.readpipe == event[0]: if self.readpipe == event[0]:
self.logger.info("Stop event received") self.logger.debug("Stop event received")
breakout = True breakout = True
break break
# A connection request was received # A connection request was received
elif self.serversock.fileno() == event[0]: elif self.serversock.fileno() == event[0]:
self.logger.info("Connection request received") self.logger.debug("Connection request received")
self.readsock, _ = self.serversock.accept() self.readsock, _ = self.serversock.accept()
self.readsock.setblocking(0) self.readsock.setblocking(0)
poll.unregister(self.serversock.fileno()) poll.unregister(self.serversock.fileno())
poll.register(self.readsock.fileno(), event_read_mask) poll.register(self.readsock.fileno(), event_read_mask)
self.logger.info("Setting connection established event") self.logger.debug("Setting connection established event")
self.connection_established.set() self.connection_established.set()
# Actual data to be logged # Actual data to be logged