xref: /openbmc/openbmc/poky/bitbake/lib/bb/ui/knotty.py (revision 03514f19)
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