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