1# 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# 8# SPDX-License-Identifier: GPL-2.0-only 9# 10 11from __future__ import division 12 13import os 14import sys 15import logging 16import progressbar 17import signal 18import bb.msg 19import time 20import fcntl 21import struct 22import copy 23import atexit 24from itertools import groupby 25 26from bb.ui import uihelper 27 28featureSet = [bb.cooker.CookerFeatures.SEND_SANITYEVENTS, bb.cooker.CookerFeatures.BASEDATASTORE_TRACKING] 29 30logger = logging.getLogger("BitBake") 31interactive = sys.stdout.isatty() 32 33class BBProgress(progressbar.ProgressBar): 34 def __init__(self, msg, maxval, widgets=None, extrapos=-1, resize_handler=None): 35 self.msg = msg 36 self.extrapos = extrapos 37 if not widgets: 38 widgets = [': ', progressbar.Percentage(), ' ', progressbar.Bar(), 39 ' ', progressbar.ETA()] 40 self.extrapos = 5 41 42 if resize_handler: 43 self._resize_default = resize_handler 44 else: 45 self._resize_default = signal.getsignal(signal.SIGWINCH) 46 progressbar.ProgressBar.__init__(self, maxval, [self.msg] + widgets, fd=sys.stdout) 47 48 def _handle_resize(self, signum=None, frame=None): 49 progressbar.ProgressBar._handle_resize(self, signum, frame) 50 if self._resize_default: 51 self._resize_default(signum, frame) 52 53 def finish(self): 54 progressbar.ProgressBar.finish(self) 55 if self._resize_default: 56 signal.signal(signal.SIGWINCH, self._resize_default) 57 58 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 68 else: 69 extrastr = '' 70 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 76class NonInteractiveProgress(object): 77 fobj = sys.stdout 78 79 def __init__(self, msg, maxval): 80 self.msg = msg 81 self.maxval = maxval 82 self.finished = False 83 84 def start(self, update=True): 85 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): 93 if self.finished: 94 return 95 self.fobj.write("done.\n") 96 self.fobj.flush() 97 self.finished = True 98 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): 113 def __init__(self, tf): 114 self.tf = tf 115 116 def filter(self, record): 117 if record.levelno == bb.msg.BBLogFormatter.NOTE and (record.msg.startswith("Running") or record.msg.startswith("recipe ")): 118 return False 119 self.tf.clearFooter() 120 return True 121 122class TerminalFilter(object): 123 rows = 25 124 columns = 80 125 126 def sigwinch_handle(self, signum, frame): 127 self.rows, self.columns = self.getTerminalColumns() 128 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: 148 cr = (os.environ['LINES'], os.environ['COLUMNS']) 149 except: 150 cr = (25, 80) 151 return cr 152 153 def __init__(self, main, helper, handlers, quiet): 154 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 = [] 161 self.lasttime = None 162 self.quiet = quiet 163 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 and os.environ.get('NO_COLOR', '') == '': 183 for h in handlers: 184 try: 185 h.formatter.enable_color() 186 except AttributeError: 187 pass 188 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 196 self.rows, self.columns = self.getTerminalColumns() 197 except: 198 self.cuu = None 199 if not self.cuu: 200 self.interactive = False 201 bb.note("Unable to use interactive mode for this terminal, using fallback") 202 return 203 204 for h in handlers: 205 h.addFilter(InteractConsoleLogFilter(self)) 206 207 self.main_progress = None 208 209 def clearFooter(self): 210 if self.footer_present: 211 lines = self.footer_present 212 sys.stdout.buffer.write(self.curses.tparm(self.cuu, lines)) 213 sys.stdout.buffer.write(self.curses.tparm(self.ed)) 214 sys.stdout.flush() 215 self.footer_present = False 216 217 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 (no events for %ds). Active tasks:" % t) 232 for t in self.helper.running_tasks: 233 print(t) 234 sys.stdout.flush() 235 236 def updateFooter(self): 237 if not self.cuu: 238 return 239 activetasks = self.helper.running_tasks 240 failedtasks = self.helper.failed_tasks 241 runningpids = self.helper.running_pids 242 currenttime = time.time() 243 if not self.lasttime or (currenttime - self.lasttime > 5): 244 self.helper.needUpdate = True 245 self.lasttime = currenttime 246 if self.footer_present and not self.helper.needUpdate: 247 return 248 self.helper.needUpdate = False 249 if self.footer_present: 250 self.clearFooter() 251 if (not self.helper.tasknumber_total or self.helper.tasknumber_current == self.helper.tasknumber_total) and not len(activetasks): 252 return 253 tasks = [] 254 for t in runningpids: 255 start_time = activetasks[t].get("starttime", None) 256 if start_time: 257 msg = "%s - %s (pid %s)" % (activetasks[t]["title"], self.elapsed(currenttime - start_time), activetasks[t]["pid"]) 258 else: 259 msg = "%s (pid %s)" % (activetasks[t]["title"], activetasks[t]["pid"]) 260 progress = activetasks[t].get("progress", None) 261 if progress is not None: 262 pbar = activetasks[t].get("progressbar", None) 263 rate = activetasks[t].get("rate", None) 264 if not pbar or pbar.bouncing != (progress < 0): 265 if progress < 0: 266 pbar = BBProgress("0: %s" % msg, 100, widgets=[' ', progressbar.BouncingSlider(), ''], extrapos=3, resize_handler=self.sigwinch_handle) 267 pbar.bouncing = True 268 else: 269 pbar = BBProgress("0: %s" % msg, 100, widgets=[' ', progressbar.Percentage(), ' ', progressbar.Bar(), ''], extrapos=5, resize_handler=self.sigwinch_handle) 270 pbar.bouncing = False 271 activetasks[t]["progressbar"] = pbar 272 tasks.append((pbar, msg, progress, rate, start_time)) 273 else: 274 tasks.append(msg) 275 276 if self.main.shutdown: 277 content = pluralise("Waiting for %s running task to finish", 278 "Waiting for %s running tasks to finish", len(activetasks)) 279 if not self.quiet: 280 content += ':' 281 print(content) 282 else: 283 scene_tasks = "%s of %s" % (self.helper.setscene_current, self.helper.setscene_total) 284 cur_tasks = "%s of %s" % (self.helper.tasknumber_current, self.helper.tasknumber_total) 285 286 content = '' 287 if not self.quiet: 288 msg = "Setscene tasks: %s" % scene_tasks 289 content += msg + "\n" 290 print(msg) 291 292 if self.quiet: 293 msg = "Running tasks (%s, %s)" % (scene_tasks, cur_tasks) 294 elif not len(activetasks): 295 msg = "No currently running tasks (%s)" % cur_tasks 296 else: 297 msg = "Currently %2s running tasks (%s)" % (len(activetasks), cur_tasks) 298 maxtask = self.helper.tasknumber_total 299 if not self.main_progress or self.main_progress.maxval != maxtask: 300 widgets = [' ', progressbar.Percentage(), ' ', progressbar.Bar()] 301 self.main_progress = BBProgress("Running tasks", maxtask, widgets=widgets, resize_handler=self.sigwinch_handle) 302 self.main_progress.start(False) 303 self.main_progress.setmessage(msg) 304 progress = max(0, self.helper.tasknumber_current - 1) 305 content += self.main_progress.update(progress) 306 print('') 307 lines = self.getlines(content) 308 if not self.quiet: 309 for tasknum, task in enumerate(tasks[:(self.rows - 1 - lines)]): 310 if isinstance(task, tuple): 311 pbar, msg, progress, rate, start_time = task 312 if not pbar.start_time: 313 pbar.start(False) 314 if start_time: 315 pbar.start_time = start_time 316 pbar.setmessage('%s: %s' % (tasknum, msg)) 317 pbar.setextra(rate) 318 if progress > -1: 319 content = pbar.update(progress) 320 else: 321 content = pbar.update(1) 322 print('') 323 else: 324 content = "%s: %s" % (tasknum, task) 325 print(content) 326 lines = lines + self.getlines(content) 327 self.footer_present = lines 328 self.lastpids = runningpids[:] 329 self.lastcount = self.helper.tasknumber_current 330 331 def getlines(self, content): 332 lines = 0 333 for line in content.split("\n"): 334 lines = lines + 1 + int(len(line) / (self.columns + 1)) 335 return lines 336 337 def finish(self): 338 if self.stdinbackup: 339 fd = sys.stdin.fileno() 340 self.termios.tcsetattr(fd, self.termios.TCSADRAIN, self.stdinbackup) 341 342def print_event_log(event, includelogs, loglines, termfilter): 343 # FIXME refactor this out further 344 logfile = event.logfile 345 if logfile and os.path.exists(logfile): 346 termfilter.clearFooter() 347 bb.error("Logfile of failure stored in: %s" % logfile) 348 if includelogs and not event.errprinted: 349 print("Log data follows:") 350 f = open(logfile, "r") 351 lines = [] 352 while True: 353 l = f.readline() 354 if l == '': 355 break 356 l = l.rstrip() 357 if loglines: 358 lines.append(' | %s' % l) 359 if len(lines) > int(loglines): 360 lines.pop(0) 361 else: 362 print('| %s' % l) 363 f.close() 364 if lines: 365 for line in lines: 366 print(line) 367 368def _log_settings_from_server(server, observe_only): 369 # Get values of variables which control our output 370 includelogs, error = server.runCommand(["getVariable", "BBINCLUDELOGS"]) 371 if error: 372 logger.error("Unable to get the value of BBINCLUDELOGS variable: %s" % error) 373 raise BaseException(error) 374 loglines, error = server.runCommand(["getVariable", "BBINCLUDELOGS_LINES"]) 375 if error: 376 logger.error("Unable to get the value of BBINCLUDELOGS_LINES variable: %s" % error) 377 raise BaseException(error) 378 if observe_only: 379 cmd = 'getVariable' 380 else: 381 cmd = 'getSetVariable' 382 consolelogfile, error = server.runCommand([cmd, "BB_CONSOLELOG"]) 383 if error: 384 logger.error("Unable to get the value of BB_CONSOLELOG variable: %s" % error) 385 raise BaseException(error) 386 logconfigfile, error = server.runCommand([cmd, "BB_LOGCONFIG"]) 387 if error: 388 logger.error("Unable to get the value of BB_LOGCONFIG variable: %s" % error) 389 raise BaseException(error) 390 return includelogs, loglines, consolelogfile, logconfigfile 391 392_evt_list = [ "bb.runqueue.runQueueExitWait", "bb.event.LogExecTTY", "logging.LogRecord", 393 "bb.build.TaskFailed", "bb.build.TaskBase", "bb.event.ParseStarted", 394 "bb.event.ParseProgress", "bb.event.ParseCompleted", "bb.event.CacheLoadStarted", 395 "bb.event.CacheLoadProgress", "bb.event.CacheLoadCompleted", "bb.command.CommandFailed", 396 "bb.command.CommandExit", "bb.command.CommandCompleted", "bb.cooker.CookerExit", 397 "bb.event.MultipleProviders", "bb.event.NoProvider", "bb.runqueue.sceneQueueTaskStarted", 398 "bb.runqueue.runQueueTaskStarted", "bb.runqueue.runQueueTaskFailed", "bb.runqueue.sceneQueueTaskFailed", 399 "bb.event.BuildBase", "bb.build.TaskStarted", "bb.build.TaskSucceeded", "bb.build.TaskFailedSilent", 400 "bb.build.TaskProgress", "bb.event.ProcessStarted", "bb.event.ProcessProgress", "bb.event.ProcessFinished"] 401 402def drain_events_errorhandling(eventHandler): 403 # We don't have logging setup, we do need to show any events we see before exiting 404 event = True 405 logger = bb.msg.logger_create('bitbake', sys.stdout) 406 while event: 407 event = eventHandler.waitEvent(0) 408 if isinstance(event, logging.LogRecord): 409 logger.handle(event) 410 411def main(server, eventHandler, params, tf = TerminalFilter): 412 413 try: 414 if not params.observe_only: 415 params.updateToServer(server, os.environ.copy()) 416 417 includelogs, loglines, consolelogfile, logconfigfile = _log_settings_from_server(server, params.observe_only) 418 419 loglevel, _ = bb.msg.constructLogOptions() 420 except bb.BBHandledException: 421 drain_events_errorhandling(eventHandler) 422 return 1 423 except Exception as e: 424 # bitbake-server comms failure 425 early_logger = bb.msg.logger_create('bitbake', sys.stdout) 426 early_logger.fatal("Attempting to set server environment: %s", e) 427 return 1 428 429 if params.options.quiet == 0: 430 console_loglevel = loglevel 431 elif params.options.quiet > 2: 432 console_loglevel = bb.msg.BBLogFormatter.ERROR 433 else: 434 console_loglevel = bb.msg.BBLogFormatter.WARNING 435 436 logconfig = { 437 "version": 1, 438 "handlers": { 439 "BitBake.console": { 440 "class": "logging.StreamHandler", 441 "formatter": "BitBake.consoleFormatter", 442 "level": console_loglevel, 443 "stream": "ext://sys.stdout", 444 "filters": ["BitBake.stdoutFilter"], 445 ".": { 446 "is_console": True, 447 }, 448 }, 449 "BitBake.errconsole": { 450 "class": "logging.StreamHandler", 451 "formatter": "BitBake.consoleFormatter", 452 "level": loglevel, 453 "stream": "ext://sys.stderr", 454 "filters": ["BitBake.stderrFilter"], 455 ".": { 456 "is_console": True, 457 }, 458 }, 459 # This handler can be used if specific loggers should print on 460 # the console at a lower severity than the default. It will 461 # display any messages sent to it that are lower than then 462 # BitBake.console logging level (so as to prevent duplication of 463 # messages). Nothing is attached to this handler by default 464 "BitBake.verbconsole": { 465 "class": "logging.StreamHandler", 466 "formatter": "BitBake.consoleFormatter", 467 "level": 1, 468 "stream": "ext://sys.stdout", 469 "filters": ["BitBake.verbconsoleFilter"], 470 ".": { 471 "is_console": True, 472 }, 473 }, 474 }, 475 "formatters": { 476 # This format instance will get color output enabled by the 477 # terminal 478 "BitBake.consoleFormatter" : { 479 "()": "bb.msg.BBLogFormatter", 480 "format": "%(levelname)s: %(message)s" 481 }, 482 # The file log requires a separate instance so that it doesn't get 483 # color enabled 484 "BitBake.logfileFormatter": { 485 "()": "bb.msg.BBLogFormatter", 486 "format": "%(levelname)s: %(message)s" 487 } 488 }, 489 "filters": { 490 "BitBake.stdoutFilter": { 491 "()": "bb.msg.LogFilterLTLevel", 492 "level": "ERROR" 493 }, 494 "BitBake.stderrFilter": { 495 "()": "bb.msg.LogFilterGEQLevel", 496 "level": "ERROR" 497 }, 498 "BitBake.verbconsoleFilter": { 499 "()": "bb.msg.LogFilterLTLevel", 500 "level": console_loglevel 501 }, 502 }, 503 "loggers": { 504 "BitBake": { 505 "level": loglevel, 506 "handlers": ["BitBake.console", "BitBake.errconsole"], 507 } 508 }, 509 "disable_existing_loggers": False 510 } 511 512 # Enable the console log file if enabled 513 if consolelogfile and not params.options.show_environment and not params.options.show_versions: 514 logconfig = bb.msg.mergeLoggingConfig(logconfig, { 515 "version": 1, 516 "handlers" : { 517 "BitBake.consolelog": { 518 "class": "logging.FileHandler", 519 "formatter": "BitBake.logfileFormatter", 520 "level": loglevel, 521 "filename": consolelogfile, 522 }, 523 # Just like verbconsole, anything sent here will go to the 524 # log file, unless it would go to BitBake.consolelog 525 "BitBake.verbconsolelog" : { 526 "class": "logging.FileHandler", 527 "formatter": "BitBake.logfileFormatter", 528 "level": 1, 529 "filename": consolelogfile, 530 "filters": ["BitBake.verbconsolelogFilter"], 531 }, 532 }, 533 "filters": { 534 "BitBake.verbconsolelogFilter": { 535 "()": "bb.msg.LogFilterLTLevel", 536 "level": loglevel, 537 }, 538 }, 539 "loggers": { 540 "BitBake": { 541 "handlers": ["BitBake.consolelog"], 542 }, 543 544 # Other interesting things that we want to keep an eye on 545 # in the log files in case someone has an issue, but not 546 # necessarily show to the user on the console 547 "BitBake.SigGen.HashEquiv": { 548 "level": "VERBOSE", 549 "handlers": ["BitBake.verbconsolelog"], 550 }, 551 "BitBake.RunQueue.HashEquiv": { 552 "level": "VERBOSE", 553 "handlers": ["BitBake.verbconsolelog"], 554 } 555 } 556 }) 557 558 bb.utils.mkdirhier(os.path.dirname(consolelogfile)) 559 loglink = os.path.join(os.path.dirname(consolelogfile), 'console-latest.log') 560 bb.utils.remove(loglink) 561 try: 562 os.symlink(os.path.basename(consolelogfile), loglink) 563 except OSError: 564 pass 565 566 # Add the logging domains specified by the user on the command line 567 for (domainarg, iterator) in groupby(params.debug_domains): 568 dlevel = len(tuple(iterator)) 569 l = logconfig["loggers"].setdefault("BitBake.%s" % domainarg, {}) 570 l["level"] = logging.DEBUG - dlevel + 1 571 l.setdefault("handlers", []).extend(["BitBake.verbconsole"]) 572 573 conf = bb.msg.setLoggingConfig(logconfig, logconfigfile) 574 575 if sys.stdin.isatty() and sys.stdout.isatty(): 576 log_exec_tty = True 577 else: 578 log_exec_tty = False 579 580 helper = uihelper.BBUIHelper() 581 582 # Look for the specially designated handlers which need to be passed to the 583 # terminal handler 584 console_handlers = [h for h in conf.config['handlers'].values() if getattr(h, 'is_console', False)] 585 586 bb.utils.set_process_name("KnottyUI") 587 588 if params.options.remote_server and params.options.kill_server: 589 server.terminateServer() 590 return 591 592 llevel, debug_domains = bb.msg.constructLogOptions() 593 try: 594 server.runCommand(["setEventMask", server.getEventHandle(), llevel, debug_domains, _evt_list]) 595 except (BrokenPipeError, EOFError) as e: 596 # bitbake-server comms failure 597 logger.fatal("Attempting to set event mask: %s", e) 598 return 1 599 600 # The logging_tree module is *extremely* helpful in debugging logging 601 # domains. Uncomment here to dump the logging tree when bitbake starts 602 #import logging_tree 603 #logging_tree.printout() 604 605 universe = False 606 if not params.observe_only: 607 try: 608 params.updateFromServer(server) 609 except Exception as e: 610 logger.fatal("Fetching command line: %s", e) 611 return 1 612 cmdline = params.parseActions() 613 if not cmdline: 614 print("Nothing to do. Use 'bitbake world' to build everything, or run 'bitbake --help' for usage information.") 615 return 1 616 if 'msg' in cmdline and cmdline['msg']: 617 logger.error(cmdline['msg']) 618 return 1 619 if cmdline['action'][0] == "buildTargets" and "universe" in cmdline['action'][1]: 620 universe = True 621 622 try: 623 ret, error = server.runCommand(cmdline['action']) 624 except (BrokenPipeError, EOFError) as e: 625 # bitbake-server comms failure 626 logger.fatal("Command '{}' failed: %s".format(cmdline), e) 627 return 1 628 if error: 629 logger.error("Command '%s' failed: %s" % (cmdline, error)) 630 return 1 631 elif not ret: 632 logger.error("Command '%s' failed: returned %s" % (cmdline, ret)) 633 return 1 634 635 636 parseprogress = None 637 cacheprogress = None 638 main.shutdown = 0 639 interrupted = False 640 return_value = 0 641 errors = 0 642 warnings = 0 643 taskfailures = [] 644 645 printintervaldelta = 10 * 60 # 10 minutes 646 printinterval = printintervaldelta 647 pinginterval = 1 * 60 # 1 minute 648 lastevent = lastprint = time.time() 649 650 termfilter = tf(main, helper, console_handlers, params.options.quiet) 651 atexit.register(termfilter.finish) 652 653 # shutdown levels 654 # 0 - normal operation 655 # 1 - no new task execution, let current running tasks finish 656 # 2 - interrupting currently executing tasks 657 # 3 - we're done, exit 658 while main.shutdown < 3: 659 try: 660 if (lastprint + printinterval) <= time.time(): 661 termfilter.keepAlive(printinterval) 662 printinterval += printintervaldelta 663 event = eventHandler.waitEvent(0) 664 if event is None: 665 if (lastevent + pinginterval) <= time.time(): 666 ret, error = server.runCommand(["ping"]) 667 if error or not ret: 668 termfilter.clearFooter() 669 print("No reply after pinging server (%s, %s), exiting." % (str(error), str(ret))) 670 return_value = 3 671 main.shutdown = 3 672 lastevent = time.time() 673 if not parseprogress: 674 termfilter.updateFooter() 675 event = eventHandler.waitEvent(0.25) 676 if event is None: 677 continue 678 lastevent = time.time() 679 helper.eventHandler(event) 680 if isinstance(event, bb.runqueue.runQueueExitWait): 681 if not main.shutdown: 682 main.shutdown = 1 683 continue 684 if isinstance(event, bb.event.LogExecTTY): 685 if log_exec_tty: 686 tries = event.retries 687 while tries: 688 print("Trying to run: %s" % event.prog) 689 if os.system(event.prog) == 0: 690 break 691 time.sleep(event.sleep_delay) 692 tries -= 1 693 if tries: 694 continue 695 logger.warning(event.msg) 696 continue 697 698 if isinstance(event, logging.LogRecord): 699 lastprint = time.time() 700 printinterval = printintervaldelta 701 if event.levelno >= bb.msg.BBLogFormatter.ERRORONCE: 702 errors = errors + 1 703 return_value = 1 704 elif event.levelno == bb.msg.BBLogFormatter.WARNING: 705 warnings = warnings + 1 706 707 if event.taskpid != 0: 708 # For "normal" logging conditions, don't show note logs from tasks 709 # but do show them if the user has changed the default log level to 710 # include verbose/debug messages 711 if event.levelno <= bb.msg.BBLogFormatter.NOTE and (event.levelno < llevel or (event.levelno == bb.msg.BBLogFormatter.NOTE and llevel != bb.msg.BBLogFormatter.VERBOSE)): 712 continue 713 714 # Prefix task messages with recipe/task 715 if event.taskpid in helper.pidmap and event.levelno not in [bb.msg.BBLogFormatter.PLAIN, bb.msg.BBLogFormatter.WARNONCE, bb.msg.BBLogFormatter.ERRORONCE]: 716 taskinfo = helper.running_tasks[helper.pidmap[event.taskpid]] 717 event.msg = taskinfo['title'] + ': ' + event.msg 718 if hasattr(event, 'fn') and event.levelno not in [bb.msg.BBLogFormatter.WARNONCE, bb.msg.BBLogFormatter.ERRORONCE]: 719 event.msg = event.fn + ': ' + event.msg 720 logging.getLogger(event.name).handle(event) 721 continue 722 723 if isinstance(event, bb.build.TaskFailedSilent): 724 logger.warning("Logfile for failed setscene task is %s" % event.logfile) 725 continue 726 if isinstance(event, bb.build.TaskFailed): 727 return_value = 1 728 print_event_log(event, includelogs, loglines, termfilter) 729 if isinstance(event, bb.build.TaskBase): 730 logger.info(event._message) 731 continue 732 if isinstance(event, bb.event.ParseStarted): 733 if params.options.quiet > 1: 734 continue 735 if event.total == 0: 736 continue 737 termfilter.clearFooter() 738 parseprogress = new_progress("Parsing recipes", event.total).start() 739 continue 740 if isinstance(event, bb.event.ParseProgress): 741 if params.options.quiet > 1: 742 continue 743 if parseprogress: 744 parseprogress.update(event.current) 745 else: 746 bb.warn("Got ParseProgress event for parsing that never started?") 747 continue 748 if isinstance(event, bb.event.ParseCompleted): 749 if params.options.quiet > 1: 750 continue 751 if not parseprogress: 752 continue 753 parseprogress.finish() 754 parseprogress = None 755 if params.options.quiet == 0: 756 print(("Parsing of %d .bb files complete (%d cached, %d parsed). %d targets, %d skipped, %d masked, %d errors." 757 % ( event.total, event.cached, event.parsed, event.virtuals, event.skipped, event.masked, event.errors))) 758 continue 759 760 if isinstance(event, bb.event.CacheLoadStarted): 761 if params.options.quiet > 1: 762 continue 763 cacheprogress = new_progress("Loading cache", event.total).start() 764 continue 765 if isinstance(event, bb.event.CacheLoadProgress): 766 if params.options.quiet > 1: 767 continue 768 cacheprogress.update(event.current) 769 continue 770 if isinstance(event, bb.event.CacheLoadCompleted): 771 if params.options.quiet > 1: 772 continue 773 cacheprogress.finish() 774 if params.options.quiet == 0: 775 print("Loaded %d entries from dependency cache." % event.num_entries) 776 continue 777 778 if isinstance(event, bb.command.CommandFailed): 779 return_value = event.exitcode 780 if event.error: 781 errors = errors + 1 782 logger.error(str(event)) 783 main.shutdown = 3 784 continue 785 if isinstance(event, bb.command.CommandExit): 786 if not return_value: 787 return_value = event.exitcode 788 main.shutdown = 3 789 continue 790 if isinstance(event, (bb.command.CommandCompleted, bb.cooker.CookerExit)): 791 main.shutdown = 3 792 continue 793 if isinstance(event, bb.event.MultipleProviders): 794 logger.info(str(event)) 795 continue 796 if isinstance(event, bb.event.NoProvider): 797 # For universe builds, only show these as warnings, not errors 798 if not universe: 799 return_value = 1 800 errors = errors + 1 801 logger.error(str(event)) 802 else: 803 logger.warning(str(event)) 804 continue 805 806 if isinstance(event, bb.runqueue.sceneQueueTaskStarted): 807 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)) 808 continue 809 810 if isinstance(event, bb.runqueue.runQueueTaskStarted): 811 if event.noexec: 812 tasktype = 'noexec task' 813 else: 814 tasktype = 'task' 815 logger.info("Running %s %d of %d (%s)", 816 tasktype, 817 event.stats.completed + event.stats.active + 818 event.stats.failed + 1, 819 event.stats.total, event.taskstring) 820 continue 821 822 if isinstance(event, bb.runqueue.runQueueTaskFailed): 823 return_value = 1 824 taskfailures.append(event.taskstring) 825 logger.error(str(event)) 826 continue 827 828 if isinstance(event, bb.runqueue.sceneQueueTaskFailed): 829 logger.warning(str(event)) 830 continue 831 832 if isinstance(event, bb.event.DepTreeGenerated): 833 continue 834 835 if isinstance(event, bb.event.ProcessStarted): 836 if params.options.quiet > 1: 837 continue 838 termfilter.clearFooter() 839 parseprogress = new_progress(event.processname, event.total) 840 parseprogress.start(False) 841 continue 842 if isinstance(event, bb.event.ProcessProgress): 843 if params.options.quiet > 1: 844 continue 845 if parseprogress: 846 parseprogress.update(event.progress) 847 else: 848 bb.warn("Got ProcessProgress event for someting that never started?") 849 continue 850 if isinstance(event, bb.event.ProcessFinished): 851 if params.options.quiet > 1: 852 continue 853 if parseprogress: 854 parseprogress.finish() 855 parseprogress = None 856 continue 857 858 # ignore 859 if isinstance(event, (bb.event.BuildBase, 860 bb.event.MetadataEvent, 861 bb.event.ConfigParsed, 862 bb.event.MultiConfigParsed, 863 bb.event.RecipeParsed, 864 bb.event.RecipePreFinalise, 865 bb.runqueue.runQueueEvent, 866 bb.event.OperationStarted, 867 bb.event.OperationCompleted, 868 bb.event.OperationProgress, 869 bb.event.DiskFull, 870 bb.event.HeartbeatEvent, 871 bb.build.TaskProgress)): 872 continue 873 874 logger.error("Unknown event: %s", event) 875 876 except (BrokenPipeError, EOFError) as e: 877 # bitbake-server comms failure, don't attempt further comms and exit 878 logger.fatal("Executing event: %s", e) 879 return_value = 1 880 errors = errors + 1 881 main.shutdown = 3 882 except EnvironmentError as ioerror: 883 termfilter.clearFooter() 884 # ignore interrupted io 885 if ioerror.args[0] == 4: 886 continue 887 sys.stderr.write(str(ioerror)) 888 main.shutdown = 2 889 if not params.observe_only: 890 try: 891 _, error = server.runCommand(["stateForceShutdown"]) 892 except (BrokenPipeError, EOFError) as e: 893 # bitbake-server comms failure, don't attempt further comms and exit 894 logger.fatal("Unable to force shutdown: %s", e) 895 main.shutdown = 3 896 except KeyboardInterrupt: 897 termfilter.clearFooter() 898 if params.observe_only: 899 print("\nKeyboard Interrupt, exiting observer...") 900 main.shutdown = 2 901 902 def state_force_shutdown(): 903 print("\nSecond Keyboard Interrupt, stopping...\n") 904 try: 905 _, error = server.runCommand(["stateForceShutdown"]) 906 if error: 907 logger.error("Unable to cleanly stop: %s" % error) 908 except (BrokenPipeError, EOFError) as e: 909 # bitbake-server comms failure 910 logger.fatal("Unable to cleanly stop: %s", e) 911 912 if not params.observe_only and main.shutdown == 1: 913 state_force_shutdown() 914 915 if not params.observe_only and main.shutdown == 0: 916 print("\nKeyboard Interrupt, closing down...\n") 917 interrupted = True 918 # Capture the second KeyboardInterrupt during stateShutdown is running 919 try: 920 _, error = server.runCommand(["stateShutdown"]) 921 if error: 922 logger.error("Unable to cleanly shutdown: %s" % error) 923 except (BrokenPipeError, EOFError) as e: 924 # bitbake-server comms failure 925 logger.fatal("Unable to cleanly shutdown: %s", e) 926 except KeyboardInterrupt: 927 state_force_shutdown() 928 929 main.shutdown = main.shutdown + 1 930 except Exception as e: 931 import traceback 932 sys.stderr.write(traceback.format_exc()) 933 main.shutdown = 2 934 if not params.observe_only: 935 try: 936 _, error = server.runCommand(["stateForceShutdown"]) 937 except (BrokenPipeError, EOFError) as e: 938 # bitbake-server comms failure, don't attempt further comms and exit 939 logger.fatal("Unable to force shutdown: %s", e) 940 main.shudown = 3 941 return_value = 1 942 try: 943 termfilter.clearFooter() 944 summary = "" 945 if taskfailures: 946 summary += pluralise("\nSummary: %s task failed:", 947 "\nSummary: %s tasks failed:", len(taskfailures)) 948 for failure in taskfailures: 949 summary += "\n %s" % failure 950 if warnings: 951 summary += pluralise("\nSummary: There was %s WARNING message.", 952 "\nSummary: There were %s WARNING messages.", warnings) 953 if return_value and errors: 954 summary += pluralise("\nSummary: There was %s ERROR message, returning a non-zero exit code.", 955 "\nSummary: There were %s ERROR messages, returning a non-zero exit code.", errors) 956 if summary and params.options.quiet == 0: 957 print(summary) 958 959 if interrupted: 960 print("Execution was interrupted, returning a non-zero exit code.") 961 if return_value == 0: 962 return_value = 1 963 except IOError as e: 964 import errno 965 if e.errno == errno.EPIPE: 966 pass 967 968 logging.shutdown() 969 970 return return_value 971