blob: 484545a6849ad764932df071c161889b467fa2c0 [file] [log] [blame]
Patrick Williamsc124f4f2015-09-15 14:41:29 -05001#
2# BitBake (No)TTY UI Implementation
3#
4# Handling output to TTYs or files (no TTY)
5#
6# Copyright (C) 2006-2012 Richard Purdie
7#
Brad Bishopc342db32019-05-15 21:57:59 -04008# SPDX-License-Identifier: GPL-2.0-only
Patrick Williamsc124f4f2015-09-15 14:41:29 -05009#
Patrick Williamsc124f4f2015-09-15 14:41:29 -050010
11from __future__ import division
12
13import os
14import sys
Patrick Williamsc124f4f2015-09-15 14:41:29 -050015import logging
16import progressbar
17import signal
18import bb.msg
19import time
20import fcntl
21import struct
22import copy
23import atexit
Andrew Geisslerc926e172021-05-07 16:11:35 -050024from itertools import groupby
Patrick Williamsc0f7c042017-02-23 20:41:17 -060025
Patrick Williamsc124f4f2015-09-15 14:41:29 -050026from bb.ui import uihelper
27
28featureSet = [bb.cooker.CookerFeatures.SEND_SANITYEVENTS]
29
30logger = logging.getLogger("BitBake")
31interactive = sys.stdout.isatty()
32
33class BBProgress(progressbar.ProgressBar):
Patrick Williamsc0f7c042017-02-23 20:41:17 -060034 def __init__(self, msg, maxval, widgets=None, extrapos=-1, resize_handler=None):
Patrick Williamsc124f4f2015-09-15 14:41:29 -050035 self.msg = msg
Patrick Williamsc0f7c042017-02-23 20:41:17 -060036 self.extrapos = extrapos
37 if not widgets:
Andrew Geissler82c905d2020-04-13 13:39:40 -050038 widgets = [': ', progressbar.Percentage(), ' ', progressbar.Bar(),
39 ' ', progressbar.ETA()]
40 self.extrapos = 5
Patrick Williamsc124f4f2015-09-15 14:41:29 -050041
Patrick Williamsc0f7c042017-02-23 20:41:17 -060042 if resize_handler:
43 self._resize_default = resize_handler
44 else:
Patrick Williamsc124f4f2015-09-15 14:41:29 -050045 self._resize_default = signal.getsignal(signal.SIGWINCH)
Andrew Geissler82c905d2020-04-13 13:39:40 -050046 progressbar.ProgressBar.__init__(self, maxval, [self.msg] + widgets, fd=sys.stdout)
Patrick Williamsc124f4f2015-09-15 14:41:29 -050047
Patrick Williamsc0f7c042017-02-23 20:41:17 -060048 def _handle_resize(self, signum=None, frame=None):
Patrick Williamsc124f4f2015-09-15 14:41:29 -050049 progressbar.ProgressBar._handle_resize(self, signum, frame)
50 if self._resize_default:
51 self._resize_default(signum, frame)
Patrick Williamsc0f7c042017-02-23 20:41:17 -060052
Patrick Williamsc124f4f2015-09-15 14:41:29 -050053 def finish(self):
54 progressbar.ProgressBar.finish(self)
55 if self._resize_default:
56 signal.signal(signal.SIGWINCH, self._resize_default)
57
Patrick Williamsc0f7c042017-02-23 20:41:17 -060058 def setmessage(self, msg):
59 self.msg = msg
60 self.widgets[0] = msg
61
62 def setextra(self, extra):
63 if self.extrapos > -1:
64 if extra:
65 extrastr = str(extra)
66 if extrastr[0] != ' ':
67 extrastr = ' ' + extrastr
Patrick Williamsc0f7c042017-02-23 20:41:17 -060068 else:
Brad Bishop6e60e8b2018-02-01 10:27:11 -050069 extrastr = ''
Patrick Williamsc0f7c042017-02-23 20:41:17 -060070 self.widgets[self.extrapos] = extrastr
71
72 def _need_update(self):
73 # We always want the bar to print when update() is called
74 return True
75
Patrick Williamsc124f4f2015-09-15 14:41:29 -050076class NonInteractiveProgress(object):
77 fobj = sys.stdout
78
79 def __init__(self, msg, maxval):
80 self.msg = msg
81 self.maxval = maxval
Patrick Williamsc0f7c042017-02-23 20:41:17 -060082 self.finished = False
Patrick Williamsc124f4f2015-09-15 14:41:29 -050083
Patrick Williamsc0f7c042017-02-23 20:41:17 -060084 def start(self, update=True):
Patrick Williamsc124f4f2015-09-15 14:41:29 -050085 self.fobj.write("%s..." % self.msg)
86 self.fobj.flush()
87 return self
88
89 def update(self, value):
90 pass
91
92 def finish(self):
Patrick Williamsc0f7c042017-02-23 20:41:17 -060093 if self.finished:
94 return
Patrick Williamsc124f4f2015-09-15 14:41:29 -050095 self.fobj.write("done.\n")
96 self.fobj.flush()
Patrick Williamsc0f7c042017-02-23 20:41:17 -060097 self.finished = True
Patrick Williamsc124f4f2015-09-15 14:41:29 -050098
99def new_progress(msg, maxval):
100 if interactive:
101 return BBProgress(msg, maxval)
102 else:
103 return NonInteractiveProgress(msg, maxval)
104
105def pluralise(singular, plural, qty):
106 if(qty == 1):
107 return singular % qty
108 else:
109 return plural % qty
110
111
112class InteractConsoleLogFilter(logging.Filter):
Andrew Geissler82c905d2020-04-13 13:39:40 -0500113 def __init__(self, tf):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500114 self.tf = tf
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500115
116 def filter(self, record):
Andrew Geissler82c905d2020-04-13 13:39:40 -0500117 if record.levelno == bb.msg.BBLogFormatter.NOTE and (record.msg.startswith("Running") or record.msg.startswith("recipe ")):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500118 return False
119 self.tf.clearFooter()
120 return True
121
122class TerminalFilter(object):
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500123 rows = 25
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500124 columns = 80
125
126 def sigwinch_handle(self, signum, frame):
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500127 self.rows, self.columns = self.getTerminalColumns()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500128 if self._sigwinch_default:
129 self._sigwinch_default(signum, frame)
130
131 def getTerminalColumns(self):
132 def ioctl_GWINSZ(fd):
133 try:
134 cr = struct.unpack('hh', fcntl.ioctl(fd, self.termios.TIOCGWINSZ, '1234'))
135 except:
136 return None
137 return cr
138 cr = ioctl_GWINSZ(sys.stdout.fileno())
139 if not cr:
140 try:
141 fd = os.open(os.ctermid(), os.O_RDONLY)
142 cr = ioctl_GWINSZ(fd)
143 os.close(fd)
144 except:
145 pass
146 if not cr:
147 try:
Andrew Geisslerc9f78652020-09-18 14:11:35 -0500148 cr = (os.environ['LINES'], os.environ['COLUMNS'])
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500149 except:
150 cr = (25, 80)
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500151 return cr
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500152
Andrew Geissler82c905d2020-04-13 13:39:40 -0500153 def __init__(self, main, helper, handlers, quiet):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500154 self.main = main
155 self.helper = helper
156 self.cuu = None
157 self.stdinbackup = None
158 self.interactive = sys.stdout.isatty()
159 self.footer_present = False
160 self.lastpids = []
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600161 self.lasttime = None
162 self.quiet = quiet
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500163
164 if not self.interactive:
165 return
166
167 try:
168 import curses
169 except ImportError:
170 sys.exit("FATAL: The knotty ui could not load the required curses python module.")
171
172 import termios
173 self.curses = curses
174 self.termios = termios
175 try:
176 fd = sys.stdin.fileno()
177 self.stdinbackup = termios.tcgetattr(fd)
178 new = copy.deepcopy(self.stdinbackup)
179 new[3] = new[3] & ~termios.ECHO
180 termios.tcsetattr(fd, termios.TCSADRAIN, new)
181 curses.setupterm()
182 if curses.tigetnum("colors") > 2:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500183 for h in handlers:
184 try:
185 h.formatter.enable_color()
186 except AttributeError:
187 pass
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500188 self.ed = curses.tigetstr("ed")
189 if self.ed:
190 self.cuu = curses.tigetstr("cuu")
191 try:
192 self._sigwinch_default = signal.getsignal(signal.SIGWINCH)
193 signal.signal(signal.SIGWINCH, self.sigwinch_handle)
194 except:
195 pass
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500196 self.rows, self.columns = self.getTerminalColumns()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500197 except:
198 self.cuu = None
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500199 if not self.cuu:
200 self.interactive = False
201 bb.note("Unable to use interactive mode for this terminal, using fallback")
202 return
Andrew Geissler82c905d2020-04-13 13:39:40 -0500203
204 for h in handlers:
205 h.addFilter(InteractConsoleLogFilter(self))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500206
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600207 self.main_progress = None
208
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500209 def clearFooter(self):
210 if self.footer_present:
211 lines = self.footer_present
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600212 sys.stdout.buffer.write(self.curses.tparm(self.cuu, lines))
213 sys.stdout.buffer.write(self.curses.tparm(self.ed))
214 sys.stdout.flush()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500215 self.footer_present = False
216
Brad Bishopc342db32019-05-15 21:57:59 -0400217 def elapsed(self, sec):
218 hrs = int(sec / 3600.0)
219 sec -= hrs * 3600
220 min = int(sec / 60.0)
221 sec -= min * 60
222 if hrs > 0:
223 return "%dh%dm%ds" % (hrs, min, sec)
224 elif min > 0:
225 return "%dm%ds" % (min, sec)
226 else:
227 return "%ds" % (sec)
228
229 def keepAlive(self, t):
230 if not self.cuu:
231 print("Bitbake still alive (%ds)" % t)
232 sys.stdout.flush()
233
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500234 def updateFooter(self):
235 if not self.cuu:
236 return
237 activetasks = self.helper.running_tasks
238 failedtasks = self.helper.failed_tasks
239 runningpids = self.helper.running_pids
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600240 currenttime = time.time()
241 if not self.lasttime or (currenttime - self.lasttime > 5):
242 self.helper.needUpdate = True
243 self.lasttime = currenttime
244 if self.footer_present and not self.helper.needUpdate:
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500245 return
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600246 self.helper.needUpdate = False
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500247 if self.footer_present:
248 self.clearFooter()
249 if (not self.helper.tasknumber_total or self.helper.tasknumber_current == self.helper.tasknumber_total) and not len(activetasks):
250 return
251 tasks = []
252 for t in runningpids:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600253 progress = activetasks[t].get("progress", None)
254 if progress is not None:
255 pbar = activetasks[t].get("progressbar", None)
256 rate = activetasks[t].get("rate", None)
257 start_time = activetasks[t].get("starttime", None)
258 if not pbar or pbar.bouncing != (progress < 0):
259 if progress < 0:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500260 pbar = BBProgress("0: %s (pid %s)" % (activetasks[t]["title"], activetasks[t]["pid"]), 100, widgets=[' ', progressbar.BouncingSlider(), ''], extrapos=3, resize_handler=self.sigwinch_handle)
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600261 pbar.bouncing = True
262 else:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500263 pbar = BBProgress("0: %s (pid %s)" % (activetasks[t]["title"], activetasks[t]["pid"]), 100, widgets=[' ', progressbar.Percentage(), ' ', progressbar.Bar(), ''], extrapos=5, resize_handler=self.sigwinch_handle)
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600264 pbar.bouncing = False
265 activetasks[t]["progressbar"] = pbar
266 tasks.append((pbar, progress, rate, start_time))
267 else:
268 start_time = activetasks[t].get("starttime", None)
269 if start_time:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500270 tasks.append("%s - %s (pid %s)" % (activetasks[t]["title"], self.elapsed(currenttime - start_time), activetasks[t]["pid"]))
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600271 else:
Andrew Geissler82c905d2020-04-13 13:39:40 -0500272 tasks.append("%s (pid %s)" % (activetasks[t]["title"], activetasks[t]["pid"]))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500273
274 if self.main.shutdown:
275 content = "Waiting for %s running tasks to finish:" % len(activetasks)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500276 print(content)
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600277 else:
278 if self.quiet:
Andrew Geisslereff27472021-10-29 15:35:00 -0500279 content = "Running tasks (%s of %s/%s of %s)" % (self.helper.setscene_current, self.helper.setscene_total, self.helper.tasknumber_current, self.helper.tasknumber_total)
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600280 elif not len(activetasks):
Andrew Geisslereff27472021-10-29 15:35:00 -0500281 content = "No currently running tasks (%s of %s/%s of %s)" % (self.helper.setscene_current, self.helper.setscene_total, self.helper.tasknumber_current, self.helper.tasknumber_total)
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600282 else:
Andrew Geisslereff27472021-10-29 15:35:00 -0500283 content = "Currently %2s running tasks (%s of %s/%s of %s)" % (len(activetasks), self.helper.setscene_current, self.helper.setscene_total, self.helper.tasknumber_current, self.helper.tasknumber_total)
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600284 maxtask = self.helper.tasknumber_total
285 if not self.main_progress or self.main_progress.maxval != maxtask:
286 widgets = [' ', progressbar.Percentage(), ' ', progressbar.Bar()]
287 self.main_progress = BBProgress("Running tasks", maxtask, widgets=widgets, resize_handler=self.sigwinch_handle)
288 self.main_progress.start(False)
289 self.main_progress.setmessage(content)
290 progress = self.helper.tasknumber_current - 1
291 if progress < 0:
292 progress = 0
293 content = self.main_progress.update(progress)
294 print('')
295 lines = 1 + int(len(content) / (self.columns + 1))
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500296 if self.quiet == 0:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600297 for tasknum, task in enumerate(tasks[:(self.rows - 2)]):
298 if isinstance(task, tuple):
299 pbar, progress, rate, start_time = task
300 if not pbar.start_time:
301 pbar.start(False)
302 if start_time:
303 pbar.start_time = start_time
304 pbar.setmessage('%s:%s' % (tasknum, pbar.msg.split(':', 1)[1]))
Brad Bishop15ae2502019-06-18 21:44:24 -0400305 pbar.setextra(rate)
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600306 if progress > -1:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600307 content = pbar.update(progress)
308 else:
309 content = pbar.update(1)
310 print('')
311 else:
312 content = "%s: %s" % (tasknum, task)
313 print(content)
314 lines = lines + 1 + int(len(content) / (self.columns + 1))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500315 self.footer_present = lines
316 self.lastpids = runningpids[:]
317 self.lastcount = self.helper.tasknumber_current
318
319 def finish(self):
320 if self.stdinbackup:
321 fd = sys.stdin.fileno()
322 self.termios.tcsetattr(fd, self.termios.TCSADRAIN, self.stdinbackup)
323
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500324def print_event_log(event, includelogs, loglines, termfilter):
325 # FIXME refactor this out further
326 logfile = event.logfile
327 if logfile and os.path.exists(logfile):
328 termfilter.clearFooter()
329 bb.error("Logfile of failure stored in: %s" % logfile)
330 if includelogs and not event.errprinted:
331 print("Log data follows:")
332 f = open(logfile, "r")
333 lines = []
334 while True:
335 l = f.readline()
336 if l == '':
337 break
338 l = l.rstrip()
339 if loglines:
340 lines.append(' | %s' % l)
341 if len(lines) > int(loglines):
342 lines.pop(0)
343 else:
344 print('| %s' % l)
345 f.close()
346 if lines:
347 for line in lines:
348 print(line)
349
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500350def _log_settings_from_server(server, observe_only):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500351 # Get values of variables which control our output
352 includelogs, error = server.runCommand(["getVariable", "BBINCLUDELOGS"])
353 if error:
354 logger.error("Unable to get the value of BBINCLUDELOGS variable: %s" % error)
355 raise BaseException(error)
356 loglines, error = server.runCommand(["getVariable", "BBINCLUDELOGS_LINES"])
357 if error:
358 logger.error("Unable to get the value of BBINCLUDELOGS_LINES variable: %s" % error)
359 raise BaseException(error)
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500360 if observe_only:
361 cmd = 'getVariable'
362 else:
363 cmd = 'getSetVariable'
364 consolelogfile, error = server.runCommand([cmd, "BB_CONSOLELOG"])
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500365 if error:
366 logger.error("Unable to get the value of BB_CONSOLELOG variable: %s" % error)
367 raise BaseException(error)
Andrew Geissler82c905d2020-04-13 13:39:40 -0500368 logconfigfile, error = server.runCommand([cmd, "BB_LOGCONFIG"])
369 if error:
370 logger.error("Unable to get the value of BB_LOGCONFIG variable: %s" % error)
371 raise BaseException(error)
372 return includelogs, loglines, consolelogfile, logconfigfile
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500373
374_evt_list = [ "bb.runqueue.runQueueExitWait", "bb.event.LogExecTTY", "logging.LogRecord",
375 "bb.build.TaskFailed", "bb.build.TaskBase", "bb.event.ParseStarted",
376 "bb.event.ParseProgress", "bb.event.ParseCompleted", "bb.event.CacheLoadStarted",
377 "bb.event.CacheLoadProgress", "bb.event.CacheLoadCompleted", "bb.command.CommandFailed",
378 "bb.command.CommandExit", "bb.command.CommandCompleted", "bb.cooker.CookerExit",
379 "bb.event.MultipleProviders", "bb.event.NoProvider", "bb.runqueue.sceneQueueTaskStarted",
380 "bb.runqueue.runQueueTaskStarted", "bb.runqueue.runQueueTaskFailed", "bb.runqueue.sceneQueueTaskFailed",
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600381 "bb.event.BuildBase", "bb.build.TaskStarted", "bb.build.TaskSucceeded", "bb.build.TaskFailedSilent",
382 "bb.build.TaskProgress", "bb.event.ProcessStarted", "bb.event.ProcessProgress", "bb.event.ProcessFinished"]
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500383
Andrew Geisslerc9f78652020-09-18 14:11:35 -0500384def drain_events_errorhandling(eventHandler):
385 # We don't have logging setup, we do need to show any events we see before exiting
386 event = True
387 logger = bb.msg.logger_create('bitbake', sys.stdout)
388 while event:
389 event = eventHandler.waitEvent(0)
390 if isinstance(event, logging.LogRecord):
391 logger.handle(event)
392
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500393def main(server, eventHandler, params, tf = TerminalFilter):
394
Andrew Geisslerc9f78652020-09-18 14:11:35 -0500395 try:
396 if not params.observe_only:
397 params.updateToServer(server, os.environ.copy())
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500398
Andrew Geisslerc9f78652020-09-18 14:11:35 -0500399 includelogs, loglines, consolelogfile, logconfigfile = _log_settings_from_server(server, params.observe_only)
Andrew Geissler82c905d2020-04-13 13:39:40 -0500400
Andrew Geisslerc9f78652020-09-18 14:11:35 -0500401 loglevel, _ = bb.msg.constructLogOptions()
402 except bb.BBHandledException:
403 drain_events_errorhandling(eventHandler)
404 return 1
Andrew Geissler82c905d2020-04-13 13:39:40 -0500405
406 if params.options.quiet == 0:
407 console_loglevel = loglevel
408 elif params.options.quiet > 2:
409 console_loglevel = bb.msg.BBLogFormatter.ERROR
410 else:
411 console_loglevel = bb.msg.BBLogFormatter.WARNING
412
413 logconfig = {
414 "version": 1,
415 "handlers": {
416 "BitBake.console": {
417 "class": "logging.StreamHandler",
418 "formatter": "BitBake.consoleFormatter",
419 "level": console_loglevel,
420 "stream": "ext://sys.stdout",
421 "filters": ["BitBake.stdoutFilter"],
422 ".": {
423 "is_console": True,
424 },
425 },
426 "BitBake.errconsole": {
427 "class": "logging.StreamHandler",
428 "formatter": "BitBake.consoleFormatter",
429 "level": loglevel,
430 "stream": "ext://sys.stderr",
431 "filters": ["BitBake.stderrFilter"],
432 ".": {
433 "is_console": True,
434 },
435 },
436 # This handler can be used if specific loggers should print on
437 # the console at a lower severity than the default. It will
438 # display any messages sent to it that are lower than then
439 # BitBake.console logging level (so as to prevent duplication of
440 # messages). Nothing is attached to this handler by default
441 "BitBake.verbconsole": {
442 "class": "logging.StreamHandler",
443 "formatter": "BitBake.consoleFormatter",
444 "level": 1,
445 "stream": "ext://sys.stdout",
446 "filters": ["BitBake.verbconsoleFilter"],
447 ".": {
448 "is_console": True,
449 },
450 },
451 },
452 "formatters": {
453 # This format instance will get color output enabled by the
454 # terminal
455 "BitBake.consoleFormatter" : {
456 "()": "bb.msg.BBLogFormatter",
457 "format": "%(levelname)s: %(message)s"
458 },
459 # The file log requires a separate instance so that it doesn't get
460 # color enabled
461 "BitBake.logfileFormatter": {
462 "()": "bb.msg.BBLogFormatter",
463 "format": "%(levelname)s: %(message)s"
464 }
465 },
466 "filters": {
467 "BitBake.stdoutFilter": {
468 "()": "bb.msg.LogFilterLTLevel",
469 "level": "ERROR"
470 },
471 "BitBake.stderrFilter": {
472 "()": "bb.msg.LogFilterGEQLevel",
473 "level": "ERROR"
474 },
475 "BitBake.verbconsoleFilter": {
476 "()": "bb.msg.LogFilterLTLevel",
477 "level": console_loglevel
478 },
479 },
480 "loggers": {
481 "BitBake": {
482 "level": loglevel,
483 "handlers": ["BitBake.console", "BitBake.errconsole"],
484 }
485 },
486 "disable_existing_loggers": False
487 }
488
489 # Enable the console log file if enabled
490 if consolelogfile and not params.options.show_environment and not params.options.show_versions:
491 logconfig = bb.msg.mergeLoggingConfig(logconfig, {
492 "version": 1,
493 "handlers" : {
494 "BitBake.consolelog": {
495 "class": "logging.FileHandler",
496 "formatter": "BitBake.logfileFormatter",
497 "level": loglevel,
498 "filename": consolelogfile,
499 },
500 # Just like verbconsole, anything sent here will go to the
501 # log file, unless it would go to BitBake.consolelog
502 "BitBake.verbconsolelog" : {
503 "class": "logging.FileHandler",
504 "formatter": "BitBake.logfileFormatter",
505 "level": 1,
506 "filename": consolelogfile,
507 "filters": ["BitBake.verbconsolelogFilter"],
508 },
509 },
510 "filters": {
511 "BitBake.verbconsolelogFilter": {
512 "()": "bb.msg.LogFilterLTLevel",
513 "level": loglevel,
514 },
515 },
516 "loggers": {
517 "BitBake": {
518 "handlers": ["BitBake.consolelog"],
519 },
520
521 # Other interesting things that we want to keep an eye on
522 # in the log files in case someone has an issue, but not
523 # necessarily show to the user on the console
524 "BitBake.SigGen.HashEquiv": {
525 "level": "VERBOSE",
526 "handlers": ["BitBake.verbconsolelog"],
527 },
528 "BitBake.RunQueue.HashEquiv": {
529 "level": "VERBOSE",
530 "handlers": ["BitBake.verbconsolelog"],
531 }
532 }
533 })
534
535 bb.utils.mkdirhier(os.path.dirname(consolelogfile))
536 loglink = os.path.join(os.path.dirname(consolelogfile), 'console-latest.log')
537 bb.utils.remove(loglink)
538 try:
539 os.symlink(os.path.basename(consolelogfile), loglink)
540 except OSError:
541 pass
542
Andrew Geisslerc926e172021-05-07 16:11:35 -0500543 # Add the logging domains specified by the user on the command line
544 for (domainarg, iterator) in groupby(params.debug_domains):
545 dlevel = len(tuple(iterator))
546 l = logconfig["loggers"].setdefault("BitBake.%s" % domainarg, {})
547 l["level"] = logging.DEBUG - dlevel + 1
548 l.setdefault("handlers", []).extend(["BitBake.verbconsole"])
549
Andrew Geissler82c905d2020-04-13 13:39:40 -0500550 conf = bb.msg.setLoggingConfig(logconfig, logconfigfile)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500551
552 if sys.stdin.isatty() and sys.stdout.isatty():
553 log_exec_tty = True
554 else:
555 log_exec_tty = False
556
557 helper = uihelper.BBUIHelper()
558
Andrew Geissler82c905d2020-04-13 13:39:40 -0500559 # Look for the specially designated handlers which need to be passed to the
560 # terminal handler
561 console_handlers = [h for h in conf.config['handlers'].values() if getattr(h, 'is_console', False)]
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500562
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500563 bb.utils.set_process_name("KnottyUI")
564
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500565 if params.options.remote_server and params.options.kill_server:
566 server.terminateServer()
567 return
568
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500569 llevel, debug_domains = bb.msg.constructLogOptions()
570 server.runCommand(["setEventMask", server.getEventHandle(), llevel, debug_domains, _evt_list])
571
Andrew Geissler82c905d2020-04-13 13:39:40 -0500572 # The logging_tree module is *extremely* helpful in debugging logging
573 # domains. Uncomment here to dump the logging tree when bitbake starts
574 #import logging_tree
575 #logging_tree.printout()
576
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500577 universe = False
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500578 if not params.observe_only:
579 params.updateFromServer(server)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500580 cmdline = params.parseActions()
581 if not cmdline:
582 print("Nothing to do. Use 'bitbake world' to build everything, or run 'bitbake --help' for usage information.")
583 return 1
584 if 'msg' in cmdline and cmdline['msg']:
585 logger.error(cmdline['msg'])
586 return 1
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500587 if cmdline['action'][0] == "buildTargets" and "universe" in cmdline['action'][1]:
588 universe = True
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500589
590 ret, error = server.runCommand(cmdline['action'])
591 if error:
592 logger.error("Command '%s' failed: %s" % (cmdline, error))
593 return 1
Andrew Geissler82c905d2020-04-13 13:39:40 -0500594 elif not ret:
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500595 logger.error("Command '%s' failed: returned %s" % (cmdline, ret))
596 return 1
597
598
599 parseprogress = None
600 cacheprogress = None
601 main.shutdown = 0
602 interrupted = False
603 return_value = 0
604 errors = 0
605 warnings = 0
606 taskfailures = []
607
Brad Bishopc342db32019-05-15 21:57:59 -0400608 printinterval = 5000
609 lastprint = time.time()
610
Andrew Geissler82c905d2020-04-13 13:39:40 -0500611 termfilter = tf(main, helper, console_handlers, params.options.quiet)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500612 atexit.register(termfilter.finish)
613
614 while True:
615 try:
Brad Bishopc342db32019-05-15 21:57:59 -0400616 if (lastprint + printinterval) <= time.time():
617 termfilter.keepAlive(printinterval)
618 printinterval += 5000
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500619 event = eventHandler.waitEvent(0)
620 if event is None:
621 if main.shutdown > 1:
622 break
Andrew Geissler82c905d2020-04-13 13:39:40 -0500623 if not parseprogress:
624 termfilter.updateFooter()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500625 event = eventHandler.waitEvent(0.25)
626 if event is None:
627 continue
628 helper.eventHandler(event)
629 if isinstance(event, bb.runqueue.runQueueExitWait):
630 if not main.shutdown:
631 main.shutdown = 1
632 continue
633 if isinstance(event, bb.event.LogExecTTY):
634 if log_exec_tty:
635 tries = event.retries
636 while tries:
637 print("Trying to run: %s" % event.prog)
638 if os.system(event.prog) == 0:
639 break
640 time.sleep(event.sleep_delay)
641 tries -= 1
642 if tries:
643 continue
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600644 logger.warning(event.msg)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500645 continue
646
647 if isinstance(event, logging.LogRecord):
Brad Bishopc342db32019-05-15 21:57:59 -0400648 lastprint = time.time()
649 printinterval = 5000
Andrew Geissler82c905d2020-04-13 13:39:40 -0500650 if event.levelno >= bb.msg.BBLogFormatter.ERROR:
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500651 errors = errors + 1
652 return_value = 1
Andrew Geissler82c905d2020-04-13 13:39:40 -0500653 elif event.levelno == bb.msg.BBLogFormatter.WARNING:
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500654 warnings = warnings + 1
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500655
656 if event.taskpid != 0:
657 # For "normal" logging conditions, don't show note logs from tasks
658 # but do show them if the user has changed the default log level to
659 # include verbose/debug messages
Andrew Geissler82c905d2020-04-13 13:39:40 -0500660 if event.levelno <= bb.msg.BBLogFormatter.NOTE and (event.levelno < llevel or (event.levelno == bb.msg.BBLogFormatter.NOTE and llevel != bb.msg.BBLogFormatter.VERBOSE)):
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500661 continue
662
663 # Prefix task messages with recipe/task
Andrew Geissler82c905d2020-04-13 13:39:40 -0500664 if event.taskpid in helper.pidmap and event.levelno != bb.msg.BBLogFormatter.PLAIN:
665 taskinfo = helper.running_tasks[helper.pidmap[event.taskpid]]
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500666 event.msg = taskinfo['title'] + ': ' + event.msg
667 if hasattr(event, 'fn'):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500668 event.msg = event.fn + ': ' + event.msg
Andrew Geissler82c905d2020-04-13 13:39:40 -0500669 logging.getLogger(event.name).handle(event)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500670 continue
671
672 if isinstance(event, bb.build.TaskFailedSilent):
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600673 logger.warning("Logfile for failed setscene task is %s" % event.logfile)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500674 continue
675 if isinstance(event, bb.build.TaskFailed):
676 return_value = 1
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500677 print_event_log(event, includelogs, loglines, termfilter)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500678 if isinstance(event, bb.build.TaskBase):
679 logger.info(event._message)
680 continue
681 if isinstance(event, bb.event.ParseStarted):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500682 if params.options.quiet > 1:
683 continue
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500684 if event.total == 0:
685 continue
Andrew Geissler82c905d2020-04-13 13:39:40 -0500686 termfilter.clearFooter()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500687 parseprogress = new_progress("Parsing recipes", event.total).start()
688 continue
689 if isinstance(event, bb.event.ParseProgress):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500690 if params.options.quiet > 1:
691 continue
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600692 if parseprogress:
693 parseprogress.update(event.current)
694 else:
695 bb.warn("Got ParseProgress event for parsing that never started?")
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500696 continue
697 if isinstance(event, bb.event.ParseCompleted):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500698 if params.options.quiet > 1:
699 continue
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500700 if not parseprogress:
701 continue
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500702 parseprogress.finish()
Andrew Geissler4c19ea12020-10-27 13:52:24 -0500703 parseprogress = None
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500704 if params.options.quiet == 0:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600705 print(("Parsing of %d .bb files complete (%d cached, %d parsed). %d targets, %d skipped, %d masked, %d errors."
706 % ( event.total, event.cached, event.parsed, event.virtuals, event.skipped, event.masked, event.errors)))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500707 continue
708
709 if isinstance(event, bb.event.CacheLoadStarted):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500710 if params.options.quiet > 1:
711 continue
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500712 cacheprogress = new_progress("Loading cache", event.total).start()
713 continue
714 if isinstance(event, bb.event.CacheLoadProgress):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500715 if params.options.quiet > 1:
716 continue
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500717 cacheprogress.update(event.current)
718 continue
719 if isinstance(event, bb.event.CacheLoadCompleted):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500720 if params.options.quiet > 1:
721 continue
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500722 cacheprogress.finish()
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500723 if params.options.quiet == 0:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600724 print("Loaded %d entries from dependency cache." % event.num_entries)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500725 continue
726
727 if isinstance(event, bb.command.CommandFailed):
728 return_value = event.exitcode
729 if event.error:
730 errors = errors + 1
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500731 logger.error(str(event))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500732 main.shutdown = 2
733 continue
734 if isinstance(event, bb.command.CommandExit):
735 if not return_value:
736 return_value = event.exitcode
Andrew Geissler82c905d2020-04-13 13:39:40 -0500737 main.shutdown = 2
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500738 continue
739 if isinstance(event, (bb.command.CommandCompleted, bb.cooker.CookerExit)):
740 main.shutdown = 2
741 continue
742 if isinstance(event, bb.event.MultipleProviders):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500743 logger.info(str(event))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500744 continue
745 if isinstance(event, bb.event.NoProvider):
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500746 # For universe builds, only show these as warnings, not errors
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500747 if not universe:
748 return_value = 1
749 errors = errors + 1
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500750 logger.error(str(event))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500751 else:
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500752 logger.warning(str(event))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500753 continue
754
755 if isinstance(event, bb.runqueue.sceneQueueTaskStarted):
Andrew Geissler5199d832021-09-24 16:47:35 -0500756 logger.info("Running setscene task %d of %d (%s)" % (event.stats.setscene_covered + event.stats.setscene_active + event.stats.setscene_notcovered + 1, event.stats.setscene_total, event.taskstring))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500757 continue
758
759 if isinstance(event, bb.runqueue.runQueueTaskStarted):
760 if event.noexec:
761 tasktype = 'noexec task'
762 else:
763 tasktype = 'task'
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600764 logger.info("Running %s %d of %d (%s)",
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500765 tasktype,
766 event.stats.completed + event.stats.active +
767 event.stats.failed + 1,
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600768 event.stats.total, event.taskstring)
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500769 continue
770
771 if isinstance(event, bb.runqueue.runQueueTaskFailed):
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500772 return_value = 1
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500773 taskfailures.append(event.taskstring)
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500774 logger.error(str(event))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500775 continue
776
777 if isinstance(event, bb.runqueue.sceneQueueTaskFailed):
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500778 logger.warning(str(event))
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500779 continue
780
781 if isinstance(event, bb.event.DepTreeGenerated):
782 continue
783
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600784 if isinstance(event, bb.event.ProcessStarted):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500785 if params.options.quiet > 1:
786 continue
Andrew Geissler82c905d2020-04-13 13:39:40 -0500787 termfilter.clearFooter()
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600788 parseprogress = new_progress(event.processname, event.total)
789 parseprogress.start(False)
790 continue
791 if isinstance(event, bb.event.ProcessProgress):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500792 if params.options.quiet > 1:
793 continue
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600794 if parseprogress:
795 parseprogress.update(event.progress)
796 else:
797 bb.warn("Got ProcessProgress event for someting that never started?")
798 continue
799 if isinstance(event, bb.event.ProcessFinished):
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500800 if params.options.quiet > 1:
801 continue
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600802 if parseprogress:
803 parseprogress.finish()
804 parseprogress = None
805 continue
806
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500807 # ignore
808 if isinstance(event, (bb.event.BuildBase,
809 bb.event.MetadataEvent,
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500810 bb.event.ConfigParsed,
Brad Bishopd7bf8c12018-02-25 22:55:05 -0500811 bb.event.MultiConfigParsed,
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500812 bb.event.RecipeParsed,
813 bb.event.RecipePreFinalise,
814 bb.runqueue.runQueueEvent,
815 bb.event.OperationStarted,
816 bb.event.OperationCompleted,
817 bb.event.OperationProgress,
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600818 bb.event.DiskFull,
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500819 bb.event.HeartbeatEvent,
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600820 bb.build.TaskProgress)):
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500821 continue
822
823 logger.error("Unknown event: %s", event)
824
825 except EnvironmentError as ioerror:
826 termfilter.clearFooter()
827 # ignore interrupted io
828 if ioerror.args[0] == 4:
829 continue
830 sys.stderr.write(str(ioerror))
831 if not params.observe_only:
832 _, error = server.runCommand(["stateForceShutdown"])
833 main.shutdown = 2
834 except KeyboardInterrupt:
835 termfilter.clearFooter()
836 if params.observe_only:
837 print("\nKeyboard Interrupt, exiting observer...")
838 main.shutdown = 2
Brad Bishop08902b02019-08-20 09:16:51 -0400839
840 def state_force_shutdown():
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500841 print("\nSecond Keyboard Interrupt, stopping...\n")
842 _, error = server.runCommand(["stateForceShutdown"])
843 if error:
844 logger.error("Unable to cleanly stop: %s" % error)
Brad Bishop08902b02019-08-20 09:16:51 -0400845
846 if not params.observe_only and main.shutdown == 1:
847 state_force_shutdown()
848
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500849 if not params.observe_only and main.shutdown == 0:
850 print("\nKeyboard Interrupt, closing down...\n")
851 interrupted = True
Brad Bishop08902b02019-08-20 09:16:51 -0400852 # Capture the second KeyboardInterrupt during stateShutdown is running
853 try:
854 _, error = server.runCommand(["stateShutdown"])
855 if error:
856 logger.error("Unable to cleanly shutdown: %s" % error)
857 except KeyboardInterrupt:
858 state_force_shutdown()
859
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500860 main.shutdown = main.shutdown + 1
861 pass
862 except Exception as e:
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500863 import traceback
864 sys.stderr.write(traceback.format_exc())
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500865 if not params.observe_only:
866 _, error = server.runCommand(["stateForceShutdown"])
867 main.shutdown = 2
Patrick Williamsd8c66bc2016-06-20 12:57:21 -0500868 return_value = 1
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500869 try:
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600870 termfilter.clearFooter()
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500871 summary = ""
872 if taskfailures:
873 summary += pluralise("\nSummary: %s task failed:",
874 "\nSummary: %s tasks failed:", len(taskfailures))
875 for failure in taskfailures:
876 summary += "\n %s" % failure
877 if warnings:
878 summary += pluralise("\nSummary: There was %s WARNING message shown.",
879 "\nSummary: There were %s WARNING messages shown.", warnings)
880 if return_value and errors:
881 summary += pluralise("\nSummary: There was %s ERROR message shown, returning a non-zero exit code.",
882 "\nSummary: There were %s ERROR messages shown, returning a non-zero exit code.", errors)
Brad Bishop6e60e8b2018-02-01 10:27:11 -0500883 if summary and params.options.quiet == 0:
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500884 print(summary)
885
886 if interrupted:
887 print("Execution was interrupted, returning a non-zero exit code.")
888 if return_value == 0:
889 return_value = 1
890 except IOError as e:
891 import errno
892 if e.errno == errno.EPIPE:
893 pass
894
Andrew Geissler82c905d2020-04-13 13:39:40 -0500895 logging.shutdown()
Patrick Williamsc0f7c042017-02-23 20:41:17 -0600896
Patrick Williamsc124f4f2015-09-15 14:41:29 -0500897 return return_value