summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorPaul Eggleton <paul.eggleton@linux.intel.com>2015-07-27 13:03:58 (GMT)
committerRichard Purdie <richard.purdie@linuxfoundation.org>2015-09-01 20:37:31 (GMT)
commit1a99652a88f541afe5ff9cb4f5aeaacbc917d40f (patch)
tree54ed073ca5fe5c82aba203cea389d18a66f16c69
parent20db29fb4d9e506aeebe863d2e4483bd7766589e (diff)
downloadpoky-1a99652a88f541afe5ff9cb4f5aeaacbc917d40f.tar.gz
oeqa/utils/qemurunner: fix logging
OE-Core commit 519e381278d40bdac79add340e4c0460a9f97e17 unfortunately broke logging in two different ways: 1) it prevented logging to the task log from working within bitbake -c testimage. This is due to the logger object being set up too early which interferes with BitBake's own logging. If we prefix the name with "BitBake." everything works (and we don't need to set the logging level). 2) Additionally because it called the log functions on the logging module and not the logger object it set up, this caused the oe-selftest logging to start printing everything from that point forward. Fix these two issues and return us to the desired behaviour for do_testimage. (From OE-Core rev: 429b1971be06d5146bb1c14f4697966cddab3b33) (From OE-Core rev: 144c6a2d711f7cf4dafc22999ed8cf4cdb329dfc) Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.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>
-rw-r--r--meta/lib/oeqa/utils/qemurunner.py49
1 files changed, 24 insertions, 25 deletions
diff --git a/meta/lib/oeqa/utils/qemurunner.py b/meta/lib/oeqa/utils/qemurunner.py
index a15990e..f12e65d 100644
--- a/meta/lib/oeqa/utils/qemurunner.py
+++ b/meta/lib/oeqa/utils/qemurunner.py
@@ -14,8 +14,7 @@ import socket
14import select 14import select
15 15
16import logging 16import logging
17logger = logging.getLogger("QemuRunner") 17logger = logging.getLogger("BitBake.QemuRunner")
18logger.setLevel(logging.DEBUG - 2)
19 18
20class QemuRunner: 19class QemuRunner:
21 20
@@ -51,11 +50,11 @@ class QemuRunner:
51 self.server_socket.bind(("127.0.0.1",0)) 50 self.server_socket.bind(("127.0.0.1",0))
52 self.server_socket.listen(2) 51 self.server_socket.listen(2)
53 self.serverport = self.server_socket.getsockname()[1] 52 self.serverport = self.server_socket.getsockname()[1]
54 logging.info("Created listening socket for qemu serial console on: 127.0.0.1:%s" % self.serverport) 53 logger.info("Created listening socket for qemu serial console on: 127.0.0.1:%s" % self.serverport)
55 return True 54 return True
56 except socket.error, msg: 55 except socket.error, msg:
57 self.server_socket.close() 56 self.server_socket.close()
58 logging.error("Failed to create listening socket: %s" % msg[1]) 57 logger.error("Failed to create listening socket: %s" % msg[1])
59 return False 58 return False
60 59
61 60
@@ -68,18 +67,18 @@ class QemuRunner:
68 if self.display: 67 if self.display:
69 os.environ["DISPLAY"] = self.display 68 os.environ["DISPLAY"] = self.display
70 else: 69 else:
71 logging.error("To start qemu I need a X desktop, please set DISPLAY correctly (e.g. DISPLAY=:1)") 70 logger.error("To start qemu I need a X desktop, please set DISPLAY correctly (e.g. DISPLAY=:1)")
72 return False 71 return False
73 if not os.path.exists(self.rootfs): 72 if not os.path.exists(self.rootfs):
74 logging.error("Invalid rootfs %s" % self.rootfs) 73 logger.error("Invalid rootfs %s" % self.rootfs)
75 return False 74 return False
76 if not os.path.exists(self.tmpdir): 75 if not os.path.exists(self.tmpdir):
77 logging.error("Invalid TMPDIR path %s" % self.tmpdir) 76 logger.error("Invalid TMPDIR path %s" % self.tmpdir)
78 return False 77 return False
79 else: 78 else:
80 os.environ["OE_TMPDIR"] = self.tmpdir 79 os.environ["OE_TMPDIR"] = self.tmpdir
81 if not os.path.exists(self.deploy_dir_image): 80 if not os.path.exists(self.deploy_dir_image):
82 logging.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image) 81 logger.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image)
83 return False 82 return False
84 else: 83 else:
85 os.environ["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image 84 os.environ["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image
@@ -97,28 +96,28 @@ class QemuRunner:
97 launch_cmd = 'runqemu %s %s %s' % (self.machine, self.rootfs, self.qemuparams) 96 launch_cmd = 'runqemu %s %s %s' % (self.machine, self.rootfs, self.qemuparams)
98 self.runqemu = subprocess.Popen(launch_cmd,shell=True,stdout=subprocess.PIPE,stderr=subprocess.STDOUT,preexec_fn=os.setpgrp) 97 self.runqemu = subprocess.Popen(launch_cmd,shell=True,stdout=subprocess.PIPE,stderr=subprocess.STDOUT,preexec_fn=os.setpgrp)
99 98
100 logging.info("runqemu started, pid is %s" % self.runqemu.pid) 99 logger.info("runqemu started, pid is %s" % self.runqemu.pid)
101 logging.info("waiting at most %s seconds for qemu pid" % self.runqemutime) 100 logger.info("waiting at most %s seconds for qemu pid" % self.runqemutime)
102 endtime = time.time() + self.runqemutime 101 endtime = time.time() + self.runqemutime
103 while not self.is_alive() and time.time() < endtime: 102 while not self.is_alive() and time.time() < endtime:
104 time.sleep(1) 103 time.sleep(1)
105 104
106 if self.is_alive(): 105 if self.is_alive():
107 logging.info("qemu started - qemu procces pid is %s" % self.qemupid) 106 logger.info("qemu started - qemu procces pid is %s" % self.qemupid)
108 cmdline = '' 107 cmdline = ''
109 with open('/proc/%s/cmdline' % self.qemupid) as p: 108 with open('/proc/%s/cmdline' % self.qemupid) as p:
110 cmdline = p.read() 109 cmdline = p.read()
111 ips = re.findall("((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1]) 110 ips = re.findall("((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1])
112 if not ips or len(ips) != 3: 111 if not ips or len(ips) != 3:
113 logging.info("Couldn't get ip from qemu process arguments! Here is the qemu command line used: %s" % cmdline) 112 logger.info("Couldn't get ip from qemu process arguments! Here is the qemu command line used: %s" % cmdline)
114 self.stop() 113 self.stop()
115 return False 114 return False
116 else: 115 else:
117 self.ip = ips[0] 116 self.ip = ips[0]
118 self.server_ip = ips[1] 117 self.server_ip = ips[1]
119 logging.info("Target IP: %s" % self.ip) 118 logger.info("Target IP: %s" % self.ip)
120 logging.info("Server IP: %s" % self.server_ip) 119 logger.info("Server IP: %s" % self.server_ip)
121 logging.info("Waiting at most %d seconds for login banner" % self.boottime) 120 logger.info("Waiting at most %d seconds for login banner" % self.boottime)
122 endtime = time.time() + self.boottime 121 endtime = time.time() + self.boottime
123 socklist = [self.server_socket] 122 socklist = [self.server_socket]
124 reachedlogin = False 123 reachedlogin = False
@@ -131,7 +130,7 @@ class QemuRunner:
131 self.qemusock.setblocking(0) 130 self.qemusock.setblocking(0)
132 socklist.append(self.qemusock) 131 socklist.append(self.qemusock)
133 socklist.remove(self.server_socket) 132 socklist.remove(self.server_socket)
134 logging.info("Connection from %s:%s" % addr) 133 logger.info("Connection from %s:%s" % addr)
135 else: 134 else:
136 data = sock.recv(1024) 135 data = sock.recv(1024)
137 if data: 136 if data:
@@ -140,24 +139,24 @@ class QemuRunner:
140 if re.search("qemu.* login:", self.bootlog): 139 if re.search("qemu.* login:", self.bootlog):
141 stopread = True 140 stopread = True
142 reachedlogin = True 141 reachedlogin = True
143 logging.info("Reached login banner") 142 logger.info("Reached login banner")
144 else: 143 else:
145 socklist.remove(sock) 144 socklist.remove(sock)
146 sock.close() 145 sock.close()
147 stopread = True 146 stopread = True
148 147
149 if not reachedlogin: 148 if not reachedlogin:
150 logging.info("Target didn't reached login boot in %d seconds" % self.boottime) 149 logger.info("Target didn't reached login boot in %d seconds" % self.boottime)
151 lines = "\n".join(self.bootlog.splitlines()[-5:]) 150 lines = "\n".join(self.bootlog.splitlines()[-5:])
152 logging.info("Last 5 lines of text:\n%s" % lines) 151 logger.info("Last 5 lines of text:\n%s" % lines)
153 logging.info("Check full boot log: %s" % self.logfile) 152 logger.info("Check full boot log: %s" % self.logfile)
154 self.stop() 153 self.stop()
155 return False 154 return False
156 else: 155 else:
157 logging.info("Qemu pid didn't appeared in %s seconds" % self.runqemutime) 156 logger.info("Qemu pid didn't appeared in %s seconds" % self.runqemutime)
158 output = self.runqemu.stdout 157 output = self.runqemu.stdout
159 self.stop() 158 self.stop()
160 logging.info("Output from runqemu:\n%s" % output.read()) 159 logger.info("Output from runqemu:\n%s" % output.read())
161 return False 160 return False
162 161
163 return self.is_alive() 162 return self.is_alive()
@@ -165,13 +164,13 @@ class QemuRunner:
165 def stop(self): 164 def stop(self):
166 165
167 if self.runqemu: 166 if self.runqemu:
168 logging.info("Sending SIGTERM to runqemu") 167 logger.info("Sending SIGTERM to runqemu")
169 os.killpg(self.runqemu.pid, signal.SIGTERM) 168 os.killpg(self.runqemu.pid, signal.SIGTERM)
170 endtime = time.time() + self.runqemutime 169 endtime = time.time() + self.runqemutime
171 while self.runqemu.poll() is None and time.time() < endtime: 170 while self.runqemu.poll() is None and time.time() < endtime:
172 time.sleep(1) 171 time.sleep(1)
173 if self.runqemu.poll() is None: 172 if self.runqemu.poll() is None:
174 logging.info("Sending SIGKILL to runqemu") 173 logger.info("Sending SIGKILL to runqemu")
175 os.killpg(self.runqemu.pid, signal.SIGKILL) 174 os.killpg(self.runqemu.pid, signal.SIGKILL)
176 self.runqemu = None 175 self.runqemu = None
177 if self.server_socket: 176 if self.server_socket:
@@ -181,7 +180,7 @@ class QemuRunner:
181 self.ip = None 180 self.ip = None
182 181
183 def restart(self, qemuparams = None): 182 def restart(self, qemuparams = None):
184 logging.info("Restarting qemu process") 183 logger.info("Restarting qemu process")
185 if self.runqemu.poll() is None: 184 if self.runqemu.poll() is None:
186 self.stop() 185 self.stop()
187 if self.start(qemuparams): 186 if self.start(qemuparams):