mirror of
git://git.yoctoproject.org/poky.git
synced 2025-07-19 12:59:02 +02:00
b2d55ec1eb
Updates hash equivalence logging so that the interesting VERBOSE messages are always logged to the consolelog file so that issues in individual user builds can be diagnosed. The autobuilder logging config then updates this so that they also are shown on stdout, since the consolelog file is not capture there. In order to facilitate this, 2 new logging handlers were added, "BitBake.verbconsole" and "BitBake.verbconsolelog". Neither of these handlers are attached to anything by default, but they will log any messages that wouldn't otherwise be logged by the normal console or consolelog handlers. Users can attach whatever loggers the desire to this handler to get them to appear on the console or in the consolelog, as demonstrated by the autobuilderlog.json file. (Bitbake rev: 766587c0baaaeb5cda3e9454395edbb70e33f756) Signed-off-by: Joshua Watt <JPEWhacker@gmail.com> Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
881 lines
34 KiB
Python
881 lines
34 KiB
Python
#
|
|
# BitBake (No)TTY UI Implementation
|
|
#
|
|
# Handling output to TTYs or files (no TTY)
|
|
#
|
|
# Copyright (C) 2006-2012 Richard Purdie
|
|
#
|
|
# SPDX-License-Identifier: GPL-2.0-only
|
|
#
|
|
|
|
from __future__ import division
|
|
|
|
import os
|
|
import sys
|
|
import logging
|
|
import progressbar
|
|
import signal
|
|
import bb.msg
|
|
import time
|
|
import fcntl
|
|
import struct
|
|
import copy
|
|
import atexit
|
|
|
|
from bb.ui import uihelper
|
|
|
|
featureSet = [bb.cooker.CookerFeatures.SEND_SANITYEVENTS]
|
|
|
|
logger = logging.getLogger("BitBake")
|
|
interactive = sys.stdout.isatty()
|
|
|
|
class BBProgress(progressbar.ProgressBar):
|
|
def __init__(self, msg, maxval, widgets=None, extrapos=-1, resize_handler=None):
|
|
self.msg = msg
|
|
self.extrapos = extrapos
|
|
if not widgets:
|
|
widgets = [': ', progressbar.Percentage(), ' ', progressbar.Bar(),
|
|
' ', progressbar.ETA()]
|
|
self.extrapos = 5
|
|
|
|
if resize_handler:
|
|
self._resize_default = resize_handler
|
|
else:
|
|
self._resize_default = signal.getsignal(signal.SIGWINCH)
|
|
progressbar.ProgressBar.__init__(self, maxval, [self.msg] + widgets, fd=sys.stdout)
|
|
|
|
def _handle_resize(self, signum=None, frame=None):
|
|
progressbar.ProgressBar._handle_resize(self, signum, frame)
|
|
if self._resize_default:
|
|
self._resize_default(signum, frame)
|
|
|
|
def finish(self):
|
|
progressbar.ProgressBar.finish(self)
|
|
if self._resize_default:
|
|
signal.signal(signal.SIGWINCH, self._resize_default)
|
|
|
|
def setmessage(self, msg):
|
|
self.msg = msg
|
|
self.widgets[0] = msg
|
|
|
|
def setextra(self, extra):
|
|
if self.extrapos > -1:
|
|
if extra:
|
|
extrastr = str(extra)
|
|
if extrastr[0] != ' ':
|
|
extrastr = ' ' + extrastr
|
|
else:
|
|
extrastr = ''
|
|
self.widgets[self.extrapos] = extrastr
|
|
|
|
def _need_update(self):
|
|
# We always want the bar to print when update() is called
|
|
return True
|
|
|
|
class NonInteractiveProgress(object):
|
|
fobj = sys.stdout
|
|
|
|
def __init__(self, msg, maxval):
|
|
self.msg = msg
|
|
self.maxval = maxval
|
|
self.finished = False
|
|
|
|
def start(self, update=True):
|
|
self.fobj.write("%s..." % self.msg)
|
|
self.fobj.flush()
|
|
return self
|
|
|
|
def update(self, value):
|
|
pass
|
|
|
|
def finish(self):
|
|
if self.finished:
|
|
return
|
|
self.fobj.write("done.\n")
|
|
self.fobj.flush()
|
|
self.finished = True
|
|
|
|
def new_progress(msg, maxval):
|
|
if interactive:
|
|
return BBProgress(msg, maxval)
|
|
else:
|
|
return NonInteractiveProgress(msg, maxval)
|
|
|
|
def pluralise(singular, plural, qty):
|
|
if(qty == 1):
|
|
return singular % qty
|
|
else:
|
|
return plural % qty
|
|
|
|
|
|
class InteractConsoleLogFilter(logging.Filter):
|
|
def __init__(self, tf):
|
|
self.tf = tf
|
|
|
|
def filter(self, record):
|
|
if record.levelno == bb.msg.BBLogFormatter.NOTE and (record.msg.startswith("Running") or record.msg.startswith("recipe ")):
|
|
return False
|
|
self.tf.clearFooter()
|
|
return True
|
|
|
|
class TerminalFilter(object):
|
|
rows = 25
|
|
columns = 80
|
|
|
|
def sigwinch_handle(self, signum, frame):
|
|
self.rows, self.columns = self.getTerminalColumns()
|
|
if self._sigwinch_default:
|
|
self._sigwinch_default(signum, frame)
|
|
|
|
def getTerminalColumns(self):
|
|
def ioctl_GWINSZ(fd):
|
|
try:
|
|
cr = struct.unpack('hh', fcntl.ioctl(fd, self.termios.TIOCGWINSZ, '1234'))
|
|
except:
|
|
return None
|
|
return cr
|
|
cr = ioctl_GWINSZ(sys.stdout.fileno())
|
|
if not cr:
|
|
try:
|
|
fd = os.open(os.ctermid(), os.O_RDONLY)
|
|
cr = ioctl_GWINSZ(fd)
|
|
os.close(fd)
|
|
except:
|
|
pass
|
|
if not cr:
|
|
try:
|
|
cr = (env['LINES'], env['COLUMNS'])
|
|
except:
|
|
cr = (25, 80)
|
|
return cr
|
|
|
|
def __init__(self, main, helper, console, errconsole, quiet):
|
|
self.main = main
|
|
self.helper = helper
|
|
self.cuu = None
|
|
self.stdinbackup = None
|
|
self.interactive = sys.stdout.isatty()
|
|
self.footer_present = False
|
|
self.lastpids = []
|
|
self.lasttime = None
|
|
self.quiet = quiet
|
|
|
|
if not self.interactive:
|
|
return
|
|
|
|
try:
|
|
import curses
|
|
except ImportError:
|
|
sys.exit("FATAL: The knotty ui could not load the required curses python module.")
|
|
|
|
import termios
|
|
self.curses = curses
|
|
self.termios = termios
|
|
try:
|
|
fd = sys.stdin.fileno()
|
|
self.stdinbackup = termios.tcgetattr(fd)
|
|
new = copy.deepcopy(self.stdinbackup)
|
|
new[3] = new[3] & ~termios.ECHO
|
|
termios.tcsetattr(fd, termios.TCSADRAIN, new)
|
|
curses.setupterm()
|
|
if curses.tigetnum("colors") > 2:
|
|
if console:
|
|
try:
|
|
console.formatter.enable_color()
|
|
except AttributeError:
|
|
pass
|
|
if errconsole:
|
|
try:
|
|
errconsole.formatter.enable_color()
|
|
except AttributeError:
|
|
pass
|
|
self.ed = curses.tigetstr("ed")
|
|
if self.ed:
|
|
self.cuu = curses.tigetstr("cuu")
|
|
try:
|
|
self._sigwinch_default = signal.getsignal(signal.SIGWINCH)
|
|
signal.signal(signal.SIGWINCH, self.sigwinch_handle)
|
|
except:
|
|
pass
|
|
self.rows, self.columns = self.getTerminalColumns()
|
|
except:
|
|
self.cuu = None
|
|
if not self.cuu:
|
|
self.interactive = False
|
|
bb.note("Unable to use interactive mode for this terminal, using fallback")
|
|
return
|
|
if console:
|
|
console.addFilter(InteractConsoleLogFilter(self))
|
|
if errconsole:
|
|
errconsole.addFilter(InteractConsoleLogFilter(self))
|
|
|
|
self.main_progress = None
|
|
|
|
def clearFooter(self):
|
|
if self.footer_present:
|
|
lines = self.footer_present
|
|
sys.stdout.buffer.write(self.curses.tparm(self.cuu, lines))
|
|
sys.stdout.buffer.write(self.curses.tparm(self.ed))
|
|
sys.stdout.flush()
|
|
self.footer_present = False
|
|
|
|
def elapsed(self, sec):
|
|
hrs = int(sec / 3600.0)
|
|
sec -= hrs * 3600
|
|
min = int(sec / 60.0)
|
|
sec -= min * 60
|
|
if hrs > 0:
|
|
return "%dh%dm%ds" % (hrs, min, sec)
|
|
elif min > 0:
|
|
return "%dm%ds" % (min, sec)
|
|
else:
|
|
return "%ds" % (sec)
|
|
|
|
def keepAlive(self, t):
|
|
if not self.cuu:
|
|
print("Bitbake still alive (%ds)" % t)
|
|
sys.stdout.flush()
|
|
|
|
def updateFooter(self):
|
|
if not self.cuu:
|
|
return
|
|
activetasks = self.helper.running_tasks
|
|
failedtasks = self.helper.failed_tasks
|
|
runningpids = self.helper.running_pids
|
|
currenttime = time.time()
|
|
if not self.lasttime or (currenttime - self.lasttime > 5):
|
|
self.helper.needUpdate = True
|
|
self.lasttime = currenttime
|
|
if self.footer_present and not self.helper.needUpdate:
|
|
return
|
|
self.helper.needUpdate = False
|
|
if self.footer_present:
|
|
self.clearFooter()
|
|
if (not self.helper.tasknumber_total or self.helper.tasknumber_current == self.helper.tasknumber_total) and not len(activetasks):
|
|
return
|
|
tasks = []
|
|
for t in runningpids:
|
|
progress = activetasks[t].get("progress", None)
|
|
if progress is not None:
|
|
pbar = activetasks[t].get("progressbar", None)
|
|
rate = activetasks[t].get("rate", None)
|
|
start_time = activetasks[t].get("starttime", None)
|
|
if not pbar or pbar.bouncing != (progress < 0):
|
|
if progress < 0:
|
|
pbar = BBProgress("0: %s (pid %s)" % (activetasks[t]["title"], activetasks[t]["pid"]), 100, widgets=[' ', progressbar.BouncingSlider(), ''], extrapos=3, resize_handler=self.sigwinch_handle)
|
|
pbar.bouncing = True
|
|
else:
|
|
pbar = BBProgress("0: %s (pid %s)" % (activetasks[t]["title"], activetasks[t]["pid"]), 100, widgets=[' ', progressbar.Percentage(), ' ', progressbar.Bar(), ''], extrapos=5, resize_handler=self.sigwinch_handle)
|
|
pbar.bouncing = False
|
|
activetasks[t]["progressbar"] = pbar
|
|
tasks.append((pbar, progress, rate, start_time))
|
|
else:
|
|
start_time = activetasks[t].get("starttime", None)
|
|
if start_time:
|
|
tasks.append("%s - %s (pid %s)" % (activetasks[t]["title"], self.elapsed(currenttime - start_time), activetasks[t]["pid"]))
|
|
else:
|
|
tasks.append("%s (pid %s)" % (activetasks[t]["title"], activetasks[t]["pid"]))
|
|
|
|
if self.main.shutdown:
|
|
content = "Waiting for %s running tasks to finish:" % len(activetasks)
|
|
print(content)
|
|
else:
|
|
if self.quiet:
|
|
content = "Running tasks (%s of %s)" % (self.helper.tasknumber_current, self.helper.tasknumber_total)
|
|
elif not len(activetasks):
|
|
content = "No currently running tasks (%s of %s)" % (self.helper.tasknumber_current, self.helper.tasknumber_total)
|
|
else:
|
|
content = "Currently %2s running tasks (%s of %s)" % (len(activetasks), self.helper.tasknumber_current, self.helper.tasknumber_total)
|
|
maxtask = self.helper.tasknumber_total
|
|
if not self.main_progress or self.main_progress.maxval != maxtask:
|
|
widgets = [' ', progressbar.Percentage(), ' ', progressbar.Bar()]
|
|
self.main_progress = BBProgress("Running tasks", maxtask, widgets=widgets, resize_handler=self.sigwinch_handle)
|
|
self.main_progress.start(False)
|
|
self.main_progress.setmessage(content)
|
|
progress = self.helper.tasknumber_current - 1
|
|
if progress < 0:
|
|
progress = 0
|
|
content = self.main_progress.update(progress)
|
|
print('')
|
|
lines = 1 + int(len(content) / (self.columns + 1))
|
|
if self.quiet == 0:
|
|
for tasknum, task in enumerate(tasks[:(self.rows - 2)]):
|
|
if isinstance(task, tuple):
|
|
pbar, progress, rate, start_time = task
|
|
if not pbar.start_time:
|
|
pbar.start(False)
|
|
if start_time:
|
|
pbar.start_time = start_time
|
|
pbar.setmessage('%s:%s' % (tasknum, pbar.msg.split(':', 1)[1]))
|
|
pbar.setextra(rate)
|
|
if progress > -1:
|
|
content = pbar.update(progress)
|
|
else:
|
|
content = pbar.update(1)
|
|
print('')
|
|
else:
|
|
content = "%s: %s" % (tasknum, task)
|
|
print(content)
|
|
lines = lines + 1 + int(len(content) / (self.columns + 1))
|
|
self.footer_present = lines
|
|
self.lastpids = runningpids[:]
|
|
self.lastcount = self.helper.tasknumber_current
|
|
|
|
def finish(self):
|
|
if self.stdinbackup:
|
|
fd = sys.stdin.fileno()
|
|
self.termios.tcsetattr(fd, self.termios.TCSADRAIN, self.stdinbackup)
|
|
|
|
def print_event_log(event, includelogs, loglines, termfilter):
|
|
# FIXME refactor this out further
|
|
logfile = event.logfile
|
|
if logfile and os.path.exists(logfile):
|
|
termfilter.clearFooter()
|
|
bb.error("Logfile of failure stored in: %s" % logfile)
|
|
if includelogs and not event.errprinted:
|
|
print("Log data follows:")
|
|
f = open(logfile, "r")
|
|
lines = []
|
|
while True:
|
|
l = f.readline()
|
|
if l == '':
|
|
break
|
|
l = l.rstrip()
|
|
if loglines:
|
|
lines.append(' | %s' % l)
|
|
if len(lines) > int(loglines):
|
|
lines.pop(0)
|
|
else:
|
|
print('| %s' % l)
|
|
f.close()
|
|
if lines:
|
|
for line in lines:
|
|
print(line)
|
|
|
|
def _log_settings_from_server(server, observe_only):
|
|
# Get values of variables which control our output
|
|
includelogs, error = server.runCommand(["getVariable", "BBINCLUDELOGS"])
|
|
if error:
|
|
logger.error("Unable to get the value of BBINCLUDELOGS variable: %s" % error)
|
|
raise BaseException(error)
|
|
loglines, error = server.runCommand(["getVariable", "BBINCLUDELOGS_LINES"])
|
|
if error:
|
|
logger.error("Unable to get the value of BBINCLUDELOGS_LINES variable: %s" % error)
|
|
raise BaseException(error)
|
|
if observe_only:
|
|
cmd = 'getVariable'
|
|
else:
|
|
cmd = 'getSetVariable'
|
|
consolelogfile, error = server.runCommand([cmd, "BB_CONSOLELOG"])
|
|
if error:
|
|
logger.error("Unable to get the value of BB_CONSOLELOG variable: %s" % error)
|
|
raise BaseException(error)
|
|
logconfigfile, error = server.runCommand([cmd, "BB_LOGCONFIG"])
|
|
if error:
|
|
logger.error("Unable to get the value of BB_LOGCONFIG variable: %s" % error)
|
|
raise BaseException(error)
|
|
return includelogs, loglines, consolelogfile, logconfigfile
|
|
|
|
_evt_list = [ "bb.runqueue.runQueueExitWait", "bb.event.LogExecTTY", "logging.LogRecord",
|
|
"bb.build.TaskFailed", "bb.build.TaskBase", "bb.event.ParseStarted",
|
|
"bb.event.ParseProgress", "bb.event.ParseCompleted", "bb.event.CacheLoadStarted",
|
|
"bb.event.CacheLoadProgress", "bb.event.CacheLoadCompleted", "bb.command.CommandFailed",
|
|
"bb.command.CommandExit", "bb.command.CommandCompleted", "bb.cooker.CookerExit",
|
|
"bb.event.MultipleProviders", "bb.event.NoProvider", "bb.runqueue.sceneQueueTaskStarted",
|
|
"bb.runqueue.runQueueTaskStarted", "bb.runqueue.runQueueTaskFailed", "bb.runqueue.sceneQueueTaskFailed",
|
|
"bb.event.BuildBase", "bb.build.TaskStarted", "bb.build.TaskSucceeded", "bb.build.TaskFailedSilent",
|
|
"bb.build.TaskProgress", "bb.event.ProcessStarted", "bb.event.ProcessProgress", "bb.event.ProcessFinished"]
|
|
|
|
def main(server, eventHandler, params, tf = TerminalFilter):
|
|
|
|
if not params.observe_only:
|
|
params.updateToServer(server, os.environ.copy())
|
|
|
|
includelogs, loglines, consolelogfile, logconfigfile = _log_settings_from_server(server, params.observe_only)
|
|
|
|
loglevel, _ = bb.msg.constructLogOptions()
|
|
|
|
if params.options.quiet == 0:
|
|
console_loglevel = loglevel
|
|
elif params.options.quiet > 2:
|
|
console_loglevel = bb.msg.BBLogFormatter.ERROR
|
|
else:
|
|
console_loglevel = bb.msg.BBLogFormatter.WARNING
|
|
|
|
logconfig = {
|
|
"version": 1,
|
|
"handlers": {
|
|
"BitBake.console": {
|
|
"class": "logging.StreamHandler",
|
|
"formatter": "BitBake.consoleFormatter",
|
|
"level": console_loglevel,
|
|
"stream": "ext://sys.stdout",
|
|
"filters": ["BitBake.stdoutFilter"],
|
|
},
|
|
"BitBake.errconsole": {
|
|
"class": "logging.StreamHandler",
|
|
"formatter": "BitBake.consoleFormatter",
|
|
"level": loglevel,
|
|
"stream": "ext://sys.stderr",
|
|
"filters": ["BitBake.stderrFilter"],
|
|
},
|
|
# This handler can be used if specific loggers should print on
|
|
# the console at a lower severity than the default. It will
|
|
# display any messages sent to it that are lower than then
|
|
# BitBake.console logging level (so as to prevent duplication of
|
|
# messages). Nothing is attached to this handler by default
|
|
"BitBake.verbconsole": {
|
|
"class": "logging.StreamHandler",
|
|
"formatter": "BitBake.consoleFormatter",
|
|
"level": 1,
|
|
"stream": "ext://sys.stdout",
|
|
"filters": ["BitBake.verbconsoleFilter"],
|
|
},
|
|
},
|
|
"formatters": {
|
|
# This format instance will get color output enabled by the
|
|
# terminal
|
|
"BitBake.consoleFormatter" : {
|
|
"()": "bb.msg.BBLogFormatter",
|
|
"format": "%(levelname)s: %(message)s"
|
|
},
|
|
# The file log requires a separate instance so that it doesn't get
|
|
# color enabled
|
|
"BitBake.logfileFormatter": {
|
|
"()": "bb.msg.BBLogFormatter",
|
|
"format": "%(levelname)s: %(message)s"
|
|
}
|
|
},
|
|
"filters": {
|
|
"BitBake.stdoutFilter": {
|
|
"()": "bb.msg.LogFilterLTLevel",
|
|
"level": "ERROR"
|
|
},
|
|
"BitBake.stderrFilter": {
|
|
"()": "bb.msg.LogFilterGEQLevel",
|
|
"level": "ERROR"
|
|
},
|
|
"BitBake.verbconsoleFilter": {
|
|
"()": "bb.msg.LogFilterLTLevel",
|
|
"level": console_loglevel
|
|
},
|
|
},
|
|
"loggers": {
|
|
"BitBake": {
|
|
"level": loglevel,
|
|
"handlers": ["BitBake.console", "BitBake.errconsole"],
|
|
}
|
|
},
|
|
"disable_existing_loggers": False
|
|
}
|
|
|
|
# Enable the console log file if enabled
|
|
if consolelogfile and not params.options.show_environment and not params.options.show_versions:
|
|
logconfig = bb.msg.mergeLoggingConfig(logconfig, {
|
|
"version": 1,
|
|
"handlers" : {
|
|
"BitBake.consolelog": {
|
|
"class": "logging.FileHandler",
|
|
"formatter": "BitBake.logfileFormatter",
|
|
"level": loglevel,
|
|
"filename": consolelogfile,
|
|
},
|
|
# Just like verbconsole, anything sent here will go to the
|
|
# log file, unless it would go to BitBake.consolelog
|
|
"BitBake.verbconsolelog" : {
|
|
"class": "logging.FileHandler",
|
|
"formatter": "BitBake.logfileFormatter",
|
|
"level": 1,
|
|
"filename": consolelogfile,
|
|
"filters": ["BitBake.verbconsolelogFilter"],
|
|
},
|
|
},
|
|
"filters": {
|
|
"BitBake.verbconsolelogFilter": {
|
|
"()": "bb.msg.LogFilterLTLevel",
|
|
"level": loglevel,
|
|
},
|
|
},
|
|
"loggers": {
|
|
"BitBake": {
|
|
"handlers": ["BitBake.consolelog"],
|
|
},
|
|
|
|
# Other interesting things that we want to keep an eye on
|
|
# in the log files in case someone has an issue, but not
|
|
# necessarily show to the user on the console
|
|
"BitBake.SigGen.HashEquiv": {
|
|
"level": "VERBOSE",
|
|
"handlers": ["BitBake.verbconsolelog"],
|
|
},
|
|
"BitBake.RunQueue.HashEquiv": {
|
|
"level": "VERBOSE",
|
|
"handlers": ["BitBake.verbconsolelog"],
|
|
}
|
|
}
|
|
})
|
|
|
|
bb.utils.mkdirhier(os.path.dirname(consolelogfile))
|
|
loglink = os.path.join(os.path.dirname(consolelogfile), 'console-latest.log')
|
|
bb.utils.remove(loglink)
|
|
try:
|
|
os.symlink(os.path.basename(consolelogfile), loglink)
|
|
except OSError:
|
|
pass
|
|
|
|
bb.msg.setLoggingConfig(logconfig, logconfigfile)
|
|
|
|
if sys.stdin.isatty() and sys.stdout.isatty():
|
|
log_exec_tty = True
|
|
else:
|
|
log_exec_tty = False
|
|
|
|
helper = uihelper.BBUIHelper()
|
|
|
|
# Look for the specially designated handlers which need to be passed to the
|
|
# terminal handler
|
|
console = None
|
|
errconsole = None
|
|
for h in logger.handlers:
|
|
name = getattr(h, '_name', None)
|
|
if name == 'BitBake.console':
|
|
console = h
|
|
elif name == 'BitBake.errconsole':
|
|
errconsole = h
|
|
|
|
bb.utils.set_process_name("KnottyUI")
|
|
|
|
if params.options.remote_server and params.options.kill_server:
|
|
server.terminateServer()
|
|
return
|
|
|
|
llevel, debug_domains = bb.msg.constructLogOptions()
|
|
server.runCommand(["setEventMask", server.getEventHandle(), llevel, debug_domains, _evt_list])
|
|
|
|
# The logging_tree module is *extremely* helpful in debugging logging
|
|
# domains. Uncomment here to dump the logging tree when bitbake starts
|
|
#import logging_tree
|
|
#logging_tree.printout()
|
|
|
|
universe = False
|
|
if not params.observe_only:
|
|
params.updateFromServer(server)
|
|
cmdline = params.parseActions()
|
|
if not cmdline:
|
|
print("Nothing to do. Use 'bitbake world' to build everything, or run 'bitbake --help' for usage information.")
|
|
return 1
|
|
if 'msg' in cmdline and cmdline['msg']:
|
|
logger.error(cmdline['msg'])
|
|
return 1
|
|
if cmdline['action'][0] == "buildTargets" and "universe" in cmdline['action'][1]:
|
|
universe = True
|
|
|
|
ret, error = server.runCommand(cmdline['action'])
|
|
if error:
|
|
logger.error("Command '%s' failed: %s" % (cmdline, error))
|
|
return 1
|
|
elif not ret:
|
|
logger.error("Command '%s' failed: returned %s" % (cmdline, ret))
|
|
return 1
|
|
|
|
|
|
parseprogress = None
|
|
cacheprogress = None
|
|
main.shutdown = 0
|
|
interrupted = False
|
|
return_value = 0
|
|
errors = 0
|
|
warnings = 0
|
|
taskfailures = []
|
|
|
|
printinterval = 5000
|
|
lastprint = time.time()
|
|
|
|
termfilter = tf(main, helper, console, errconsole, params.options.quiet)
|
|
atexit.register(termfilter.finish)
|
|
|
|
while True:
|
|
try:
|
|
if (lastprint + printinterval) <= time.time():
|
|
termfilter.keepAlive(printinterval)
|
|
printinterval += 5000
|
|
event = eventHandler.waitEvent(0)
|
|
if event is None:
|
|
if main.shutdown > 1:
|
|
break
|
|
if not parseprogress:
|
|
termfilter.updateFooter()
|
|
event = eventHandler.waitEvent(0.25)
|
|
if event is None:
|
|
continue
|
|
helper.eventHandler(event)
|
|
if isinstance(event, bb.runqueue.runQueueExitWait):
|
|
if not main.shutdown:
|
|
main.shutdown = 1
|
|
continue
|
|
if isinstance(event, bb.event.LogExecTTY):
|
|
if log_exec_tty:
|
|
tries = event.retries
|
|
while tries:
|
|
print("Trying to run: %s" % event.prog)
|
|
if os.system(event.prog) == 0:
|
|
break
|
|
time.sleep(event.sleep_delay)
|
|
tries -= 1
|
|
if tries:
|
|
continue
|
|
logger.warning(event.msg)
|
|
continue
|
|
|
|
if isinstance(event, logging.LogRecord):
|
|
lastprint = time.time()
|
|
printinterval = 5000
|
|
if event.levelno >= bb.msg.BBLogFormatter.ERROR:
|
|
errors = errors + 1
|
|
return_value = 1
|
|
elif event.levelno == bb.msg.BBLogFormatter.WARNING:
|
|
warnings = warnings + 1
|
|
|
|
if event.taskpid != 0:
|
|
# For "normal" logging conditions, don't show note logs from tasks
|
|
# but do show them if the user has changed the default log level to
|
|
# include verbose/debug messages
|
|
if event.levelno <= bb.msg.BBLogFormatter.NOTE and (event.levelno < llevel or (event.levelno == bb.msg.BBLogFormatter.NOTE and llevel != bb.msg.BBLogFormatter.VERBOSE)):
|
|
continue
|
|
|
|
# Prefix task messages with recipe/task
|
|
if event.taskpid in helper.pidmap and event.levelno != bb.msg.BBLogFormatter.PLAIN:
|
|
taskinfo = helper.running_tasks[helper.pidmap[event.taskpid]]
|
|
event.msg = taskinfo['title'] + ': ' + event.msg
|
|
if hasattr(event, 'fn'):
|
|
event.msg = event.fn + ': ' + event.msg
|
|
logging.getLogger(event.name).handle(event)
|
|
continue
|
|
|
|
if isinstance(event, bb.build.TaskFailedSilent):
|
|
logger.warning("Logfile for failed setscene task is %s" % event.logfile)
|
|
continue
|
|
if isinstance(event, bb.build.TaskFailed):
|
|
return_value = 1
|
|
print_event_log(event, includelogs, loglines, termfilter)
|
|
if isinstance(event, bb.build.TaskBase):
|
|
logger.info(event._message)
|
|
continue
|
|
if isinstance(event, bb.event.ParseStarted):
|
|
if params.options.quiet > 1:
|
|
continue
|
|
if event.total == 0:
|
|
continue
|
|
termfilter.clearFooter()
|
|
parseprogress = new_progress("Parsing recipes", event.total).start()
|
|
continue
|
|
if isinstance(event, bb.event.ParseProgress):
|
|
if params.options.quiet > 1:
|
|
continue
|
|
if parseprogress:
|
|
parseprogress.update(event.current)
|
|
else:
|
|
bb.warn("Got ParseProgress event for parsing that never started?")
|
|
continue
|
|
if isinstance(event, bb.event.ParseCompleted):
|
|
if params.options.quiet > 1:
|
|
continue
|
|
if not parseprogress:
|
|
continue
|
|
parseprogress.finish()
|
|
pasreprogress = None
|
|
if params.options.quiet == 0:
|
|
print(("Parsing of %d .bb files complete (%d cached, %d parsed). %d targets, %d skipped, %d masked, %d errors."
|
|
% ( event.total, event.cached, event.parsed, event.virtuals, event.skipped, event.masked, event.errors)))
|
|
continue
|
|
|
|
if isinstance(event, bb.event.CacheLoadStarted):
|
|
if params.options.quiet > 1:
|
|
continue
|
|
cacheprogress = new_progress("Loading cache", event.total).start()
|
|
continue
|
|
if isinstance(event, bb.event.CacheLoadProgress):
|
|
if params.options.quiet > 1:
|
|
continue
|
|
cacheprogress.update(event.current)
|
|
continue
|
|
if isinstance(event, bb.event.CacheLoadCompleted):
|
|
if params.options.quiet > 1:
|
|
continue
|
|
cacheprogress.finish()
|
|
if params.options.quiet == 0:
|
|
print("Loaded %d entries from dependency cache." % event.num_entries)
|
|
continue
|
|
|
|
if isinstance(event, bb.command.CommandFailed):
|
|
return_value = event.exitcode
|
|
if event.error:
|
|
errors = errors + 1
|
|
logger.error(str(event))
|
|
main.shutdown = 2
|
|
continue
|
|
if isinstance(event, bb.command.CommandExit):
|
|
if not return_value:
|
|
return_value = event.exitcode
|
|
main.shutdown = 2
|
|
continue
|
|
if isinstance(event, (bb.command.CommandCompleted, bb.cooker.CookerExit)):
|
|
main.shutdown = 2
|
|
continue
|
|
if isinstance(event, bb.event.MultipleProviders):
|
|
logger.info(str(event))
|
|
continue
|
|
if isinstance(event, bb.event.NoProvider):
|
|
# For universe builds, only show these as warnings, not errors
|
|
if not universe:
|
|
return_value = 1
|
|
errors = errors + 1
|
|
logger.error(str(event))
|
|
else:
|
|
logger.warning(str(event))
|
|
continue
|
|
|
|
if isinstance(event, bb.runqueue.sceneQueueTaskStarted):
|
|
logger.info("Running setscene task %d of %d (%s)" % (event.stats.completed + event.stats.active + event.stats.failed + 1, event.stats.total, event.taskstring))
|
|
continue
|
|
|
|
if isinstance(event, bb.runqueue.runQueueTaskStarted):
|
|
if event.noexec:
|
|
tasktype = 'noexec task'
|
|
else:
|
|
tasktype = 'task'
|
|
logger.info("Running %s %d of %d (%s)",
|
|
tasktype,
|
|
event.stats.completed + event.stats.active +
|
|
event.stats.failed + 1,
|
|
event.stats.total, event.taskstring)
|
|
continue
|
|
|
|
if isinstance(event, bb.runqueue.runQueueTaskFailed):
|
|
return_value = 1
|
|
taskfailures.append(event.taskstring)
|
|
logger.error(str(event))
|
|
continue
|
|
|
|
if isinstance(event, bb.runqueue.sceneQueueTaskFailed):
|
|
logger.warning(str(event))
|
|
continue
|
|
|
|
if isinstance(event, bb.event.DepTreeGenerated):
|
|
continue
|
|
|
|
if isinstance(event, bb.event.ProcessStarted):
|
|
if params.options.quiet > 1:
|
|
continue
|
|
termfilter.clearFooter()
|
|
parseprogress = new_progress(event.processname, event.total)
|
|
parseprogress.start(False)
|
|
continue
|
|
if isinstance(event, bb.event.ProcessProgress):
|
|
if params.options.quiet > 1:
|
|
continue
|
|
if parseprogress:
|
|
parseprogress.update(event.progress)
|
|
else:
|
|
bb.warn("Got ProcessProgress event for someting that never started?")
|
|
continue
|
|
if isinstance(event, bb.event.ProcessFinished):
|
|
if params.options.quiet > 1:
|
|
continue
|
|
if parseprogress:
|
|
parseprogress.finish()
|
|
parseprogress = None
|
|
continue
|
|
|
|
# ignore
|
|
if isinstance(event, (bb.event.BuildBase,
|
|
bb.event.MetadataEvent,
|
|
bb.event.ConfigParsed,
|
|
bb.event.MultiConfigParsed,
|
|
bb.event.RecipeParsed,
|
|
bb.event.RecipePreFinalise,
|
|
bb.runqueue.runQueueEvent,
|
|
bb.event.OperationStarted,
|
|
bb.event.OperationCompleted,
|
|
bb.event.OperationProgress,
|
|
bb.event.DiskFull,
|
|
bb.event.HeartbeatEvent,
|
|
bb.build.TaskProgress)):
|
|
continue
|
|
|
|
logger.error("Unknown event: %s", event)
|
|
|
|
except EnvironmentError as ioerror:
|
|
termfilter.clearFooter()
|
|
# ignore interrupted io
|
|
if ioerror.args[0] == 4:
|
|
continue
|
|
sys.stderr.write(str(ioerror))
|
|
if not params.observe_only:
|
|
_, error = server.runCommand(["stateForceShutdown"])
|
|
main.shutdown = 2
|
|
except KeyboardInterrupt:
|
|
termfilter.clearFooter()
|
|
if params.observe_only:
|
|
print("\nKeyboard Interrupt, exiting observer...")
|
|
main.shutdown = 2
|
|
|
|
def state_force_shutdown():
|
|
print("\nSecond Keyboard Interrupt, stopping...\n")
|
|
_, error = server.runCommand(["stateForceShutdown"])
|
|
if error:
|
|
logger.error("Unable to cleanly stop: %s" % error)
|
|
|
|
if not params.observe_only and main.shutdown == 1:
|
|
state_force_shutdown()
|
|
|
|
if not params.observe_only and main.shutdown == 0:
|
|
print("\nKeyboard Interrupt, closing down...\n")
|
|
interrupted = True
|
|
# Capture the second KeyboardInterrupt during stateShutdown is running
|
|
try:
|
|
_, error = server.runCommand(["stateShutdown"])
|
|
if error:
|
|
logger.error("Unable to cleanly shutdown: %s" % error)
|
|
except KeyboardInterrupt:
|
|
state_force_shutdown()
|
|
|
|
main.shutdown = main.shutdown + 1
|
|
pass
|
|
except Exception as e:
|
|
import traceback
|
|
sys.stderr.write(traceback.format_exc())
|
|
if not params.observe_only:
|
|
_, error = server.runCommand(["stateForceShutdown"])
|
|
main.shutdown = 2
|
|
return_value = 1
|
|
try:
|
|
termfilter.clearFooter()
|
|
summary = ""
|
|
if taskfailures:
|
|
summary += pluralise("\nSummary: %s task failed:",
|
|
"\nSummary: %s tasks failed:", len(taskfailures))
|
|
for failure in taskfailures:
|
|
summary += "\n %s" % failure
|
|
if warnings:
|
|
summary += pluralise("\nSummary: There was %s WARNING message shown.",
|
|
"\nSummary: There were %s WARNING messages shown.", warnings)
|
|
if return_value and errors:
|
|
summary += pluralise("\nSummary: There was %s ERROR message shown, returning a non-zero exit code.",
|
|
"\nSummary: There were %s ERROR messages shown, returning a non-zero exit code.", errors)
|
|
if summary and params.options.quiet == 0:
|
|
print(summary)
|
|
|
|
if interrupted:
|
|
print("Execution was interrupted, returning a non-zero exit code.")
|
|
if return_value == 0:
|
|
return_value = 1
|
|
except IOError as e:
|
|
import errno
|
|
if e.errno == errno.EPIPE:
|
|
pass
|
|
|
|
bb.msg.cleanupLogging()
|
|
|
|
return return_value
|