mirror of
git://git.yoctoproject.org/poky.git
synced 2025-07-19 21:09:03 +02:00

The intended usage is for recording current system statistics from /proc in buildstats.bbclass during a build and for improving the BB_DISKMON_DIRS implementation. All other existing hooks are less suitable because they trigger at unpredictable rates: too often can be handled by doing rate-limiting in the event handler, but not often enough (for example, when there is only one long-running task) cannot because the handler does not get called at all. The implementation of the new heartbeat event hooks into the cooker process event queue. The process already wakes up every 0.1s, which is often enough for the intentionally coarse 1s delay between heartbeats. That value was chosen to keep the overhead low while still being frequent enough for the intended usage. If necessary, BB_HEARTBEAT_EVENT can be set to a float specifying the delay in seconds between these heartbeat events. (Bitbake rev: 7cf22ea057d28c54bd98dc1ab7a43402a29ff1f5) Signed-off-by: Patrick Ohly <patrick.ohly@intel.com> Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
507 lines
20 KiB
Python
507 lines
20 KiB
Python
#
|
|
# BitBake ToasterUI Implementation
|
|
# based on (No)TTY UI Implementation by Richard Purdie
|
|
#
|
|
# Handling output to TTYs or files (no TTY)
|
|
#
|
|
# Copyright (C) 2006-2012 Richard Purdie
|
|
# Copyright (C) 2013 Intel Corporation
|
|
#
|
|
# This program is free software; you can redistribute it and/or modify
|
|
# it under the terms of the GNU General Public License version 2 as
|
|
# published by the Free Software Foundation.
|
|
#
|
|
# This program is distributed in the hope that it will be useful,
|
|
# but WITHOUT ANY WARRANTY; without even the implied warranty of
|
|
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
|
|
# GNU General Public License for more details.
|
|
#
|
|
# You should have received a copy of the GNU General Public License along
|
|
# with this program; if not, write to the Free Software Foundation, Inc.,
|
|
# 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
|
|
|
|
from __future__ import division
|
|
import time
|
|
import sys
|
|
try:
|
|
import bb
|
|
except RuntimeError as exc:
|
|
sys.exit(str(exc))
|
|
|
|
from bb.ui import uihelper
|
|
from bb.ui.buildinfohelper import BuildInfoHelper
|
|
|
|
import bb.msg
|
|
import logging
|
|
import os
|
|
|
|
# pylint: disable=invalid-name
|
|
# module properties for UI modules are read by bitbake and the contract should not be broken
|
|
|
|
|
|
featureSet = [bb.cooker.CookerFeatures.HOB_EXTRA_CACHES, bb.cooker.CookerFeatures.BASEDATASTORE_TRACKING, bb.cooker.CookerFeatures.SEND_SANITYEVENTS]
|
|
|
|
logger = logging.getLogger("ToasterLogger")
|
|
interactive = sys.stdout.isatty()
|
|
|
|
def _log_settings_from_server(server):
|
|
# 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)
|
|
consolelogfile, error = server.runCommand(["getVariable", "BB_CONSOLELOG"])
|
|
if error:
|
|
logger.error("Unable to get the value of BB_CONSOLELOG variable: %s", error)
|
|
raise BaseException(error)
|
|
return consolelogfile
|
|
|
|
# create a log file for a single build and direct the logger at it;
|
|
# log file name is timestamped to the millisecond (depending
|
|
# on system clock accuracy) to ensure it doesn't overlap with
|
|
# other log file names
|
|
#
|
|
# returns (log file, path to log file) for a build
|
|
def _open_build_log(log_dir):
|
|
format_str = "%(levelname)s: %(message)s"
|
|
|
|
now = time.time()
|
|
now_ms = int((now - int(now)) * 1000)
|
|
time_str = time.strftime('build_%Y%m%d_%H%M%S', time.localtime(now))
|
|
log_file_name = time_str + ('.%d.log' % now_ms)
|
|
build_log_file_path = os.path.join(log_dir, log_file_name)
|
|
|
|
build_log = logging.FileHandler(build_log_file_path)
|
|
|
|
logformat = bb.msg.BBLogFormatter(format_str)
|
|
build_log.setFormatter(logformat)
|
|
|
|
bb.msg.addDefaultlogFilter(build_log)
|
|
logger.addHandler(build_log)
|
|
|
|
return (build_log, build_log_file_path)
|
|
|
|
# stop logging to the build log if it exists
|
|
def _close_build_log(build_log):
|
|
if build_log:
|
|
build_log.flush()
|
|
build_log.close()
|
|
logger.removeHandler(build_log)
|
|
|
|
_evt_list = [
|
|
"bb.build.TaskBase",
|
|
"bb.build.TaskFailed",
|
|
"bb.build.TaskFailedSilent",
|
|
"bb.build.TaskStarted",
|
|
"bb.build.TaskSucceeded",
|
|
"bb.command.CommandCompleted",
|
|
"bb.command.CommandExit",
|
|
"bb.command.CommandFailed",
|
|
"bb.cooker.CookerExit",
|
|
"bb.event.BuildInit",
|
|
"bb.event.BuildCompleted",
|
|
"bb.event.BuildStarted",
|
|
"bb.event.CacheLoadCompleted",
|
|
"bb.event.CacheLoadProgress",
|
|
"bb.event.CacheLoadStarted",
|
|
"bb.event.ConfigParsed",
|
|
"bb.event.DepTreeGenerated",
|
|
"bb.event.LogExecTTY",
|
|
"bb.event.MetadataEvent",
|
|
"bb.event.MultipleProviders",
|
|
"bb.event.NoProvider",
|
|
"bb.event.ParseCompleted",
|
|
"bb.event.ParseProgress",
|
|
"bb.event.ParseStarted",
|
|
"bb.event.RecipeParsed",
|
|
"bb.event.SanityCheck",
|
|
"bb.event.SanityCheckPassed",
|
|
"bb.event.TreeDataPreparationCompleted",
|
|
"bb.event.TreeDataPreparationStarted",
|
|
"bb.runqueue.runQueueTaskCompleted",
|
|
"bb.runqueue.runQueueTaskFailed",
|
|
"bb.runqueue.runQueueTaskSkipped",
|
|
"bb.runqueue.runQueueTaskStarted",
|
|
"bb.runqueue.sceneQueueTaskCompleted",
|
|
"bb.runqueue.sceneQueueTaskFailed",
|
|
"bb.runqueue.sceneQueueTaskStarted",
|
|
"logging.LogRecord"]
|
|
|
|
def main(server, eventHandler, params):
|
|
# set to a logging.FileHandler instance when a build starts;
|
|
# see _open_build_log()
|
|
build_log = None
|
|
|
|
# set to the log path when a build starts
|
|
build_log_file_path = None
|
|
|
|
helper = uihelper.BBUIHelper()
|
|
|
|
# TODO don't use log output to determine when bitbake has started
|
|
#
|
|
# WARNING: this log handler cannot be removed, as localhostbecontroller
|
|
# relies on output in the toaster_ui.log file to determine whether
|
|
# the bitbake server has started, which only happens if
|
|
# this logger is setup here (see the TODO in the loop below)
|
|
console = logging.StreamHandler(sys.stdout)
|
|
format_str = "%(levelname)s: %(message)s"
|
|
formatter = bb.msg.BBLogFormatter(format_str)
|
|
bb.msg.addDefaultlogFilter(console)
|
|
console.setFormatter(formatter)
|
|
logger.addHandler(console)
|
|
logger.setLevel(logging.INFO)
|
|
llevel, debug_domains = bb.msg.constructLogOptions()
|
|
result, error = server.runCommand(["setEventMask", server.getEventHandle(), llevel, debug_domains, _evt_list])
|
|
if not result or error:
|
|
logger.error("can't set event mask: %s", error)
|
|
return 1
|
|
|
|
# verify and warn
|
|
build_history_enabled = True
|
|
inheritlist, _ = server.runCommand(["getVariable", "INHERIT"])
|
|
|
|
if not "buildhistory" in inheritlist.split(" "):
|
|
logger.warning("buildhistory is not enabled. Please enable INHERIT += \"buildhistory\" to see image details.")
|
|
build_history_enabled = False
|
|
|
|
if not "buildstats" in inheritlist.split(" "):
|
|
logger.warning("buildstats is not enabled. Please enable INHERIT += \"buildstats\" to generate build statistics.")
|
|
|
|
if not params.observe_only:
|
|
params.updateFromServer(server)
|
|
params.updateToServer(server, os.environ.copy())
|
|
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
|
|
|
|
ret, error = server.runCommand(cmdline['action'])
|
|
if error:
|
|
logger.error("Command '%s' failed: %s" % (cmdline, error))
|
|
return 1
|
|
elif ret != True:
|
|
logger.error("Command '%s' failed: returned %s" % (cmdline, ret))
|
|
return 1
|
|
|
|
# set to 1 when toasterui needs to shut down
|
|
main.shutdown = 0
|
|
|
|
interrupted = False
|
|
return_value = 0
|
|
errors = 0
|
|
warnings = 0
|
|
taskfailures = []
|
|
first = True
|
|
|
|
buildinfohelper = BuildInfoHelper(server, build_history_enabled,
|
|
os.getenv('TOASTER_BRBE'))
|
|
|
|
# write our own log files into bitbake's log directory;
|
|
# we're only interested in the path to the parent directory of
|
|
# this file, as we're writing our own logs into the same directory
|
|
consolelogfile = _log_settings_from_server(server)
|
|
log_dir = os.path.dirname(consolelogfile)
|
|
bb.utils.mkdirhier(log_dir)
|
|
|
|
while True:
|
|
try:
|
|
event = eventHandler.waitEvent(0.25)
|
|
if first:
|
|
first = False
|
|
|
|
# TODO don't use log output to determine when bitbake has started
|
|
#
|
|
# this is the line localhostbecontroller needs to
|
|
# see in toaster_ui.log which it uses to decide whether
|
|
# the bitbake server has started...
|
|
logger.info("ToasterUI waiting for events")
|
|
|
|
if event is None:
|
|
if main.shutdown > 0:
|
|
# if shutting down, close any open build log first
|
|
_close_build_log(build_log)
|
|
|
|
break
|
|
continue
|
|
|
|
helper.eventHandler(event)
|
|
|
|
# pylint: disable=protected-access
|
|
# the code will look into the protected variables of the event; no easy way around this
|
|
|
|
if isinstance(event, bb.event.HeartbeatEvent):
|
|
continue
|
|
|
|
if isinstance(event, bb.event.ParseStarted):
|
|
if not (build_log and build_log_file_path):
|
|
build_log, build_log_file_path = _open_build_log(log_dir)
|
|
|
|
buildinfohelper.store_started_build()
|
|
buildinfohelper.save_build_log_file_path(build_log_file_path)
|
|
buildinfohelper.set_recipes_to_parse(event.total)
|
|
continue
|
|
|
|
# create a build object in buildinfohelper from either BuildInit
|
|
# (if available) or BuildStarted (for jethro and previous versions)
|
|
if isinstance(event, (bb.event.BuildStarted, bb.event.BuildInit)):
|
|
if not (build_log and build_log_file_path):
|
|
build_log, build_log_file_path = _open_build_log(log_dir)
|
|
|
|
buildinfohelper.save_build_targets(event)
|
|
buildinfohelper.save_build_log_file_path(build_log_file_path)
|
|
|
|
# get additional data from BuildStarted
|
|
if isinstance(event, bb.event.BuildStarted):
|
|
buildinfohelper.save_build_layers_and_variables()
|
|
continue
|
|
|
|
if isinstance(event, bb.event.ParseProgress):
|
|
buildinfohelper.set_recipes_parsed(event.current)
|
|
continue
|
|
|
|
if isinstance(event, bb.event.ParseCompleted):
|
|
buildinfohelper.set_recipes_parsed(event.total)
|
|
continue
|
|
|
|
if isinstance(event, (bb.build.TaskStarted, bb.build.TaskSucceeded, bb.build.TaskFailedSilent)):
|
|
buildinfohelper.update_and_store_task(event)
|
|
logger.info("Logfile for task %s", event.logfile)
|
|
continue
|
|
|
|
if isinstance(event, bb.build.TaskBase):
|
|
logger.info(event._message)
|
|
|
|
if isinstance(event, bb.event.LogExecTTY):
|
|
logger.info(event.msg)
|
|
continue
|
|
|
|
if isinstance(event, logging.LogRecord):
|
|
if event.levelno == -1:
|
|
event.levelno = formatter.ERROR
|
|
|
|
buildinfohelper.store_log_event(event)
|
|
|
|
if event.levelno >= formatter.ERROR:
|
|
errors = errors + 1
|
|
elif event.levelno == formatter.WARNING:
|
|
warnings = warnings + 1
|
|
|
|
# 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.taskpid != 0 and event.levelno <= formatter.NOTE:
|
|
continue
|
|
|
|
logger.handle(event)
|
|
continue
|
|
|
|
if isinstance(event, bb.build.TaskFailed):
|
|
buildinfohelper.update_and_store_task(event)
|
|
logfile = event.logfile
|
|
if logfile and os.path.exists(logfile):
|
|
bb.error("Logfile of failure stored in: %s" % logfile)
|
|
continue
|
|
|
|
# these events are unprocessed now, but may be used in the future to log
|
|
# timing and error informations from the parsing phase in Toaster
|
|
if isinstance(event, (bb.event.SanityCheckPassed, bb.event.SanityCheck)):
|
|
continue
|
|
if isinstance(event, bb.event.CacheLoadStarted):
|
|
continue
|
|
if isinstance(event, bb.event.CacheLoadProgress):
|
|
continue
|
|
if isinstance(event, bb.event.CacheLoadCompleted):
|
|
continue
|
|
if isinstance(event, bb.event.MultipleProviders):
|
|
logger.info("multiple providers are available for %s%s (%s)", event._is_runtime and "runtime " or "",
|
|
event._item,
|
|
", ".join(event._candidates))
|
|
logger.info("consider defining a PREFERRED_PROVIDER entry to match %s", event._item)
|
|
continue
|
|
|
|
if isinstance(event, bb.event.NoProvider):
|
|
errors = errors + 1
|
|
if event._runtime:
|
|
r = "R"
|
|
else:
|
|
r = ""
|
|
|
|
if event._dependees:
|
|
text = "Nothing %sPROVIDES '%s' (but %s %sDEPENDS on or otherwise requires it)" % (r, event._item, ", ".join(event._dependees), r)
|
|
else:
|
|
text = "Nothing %sPROVIDES '%s'" % (r, event._item)
|
|
|
|
logger.error(text)
|
|
if event._reasons:
|
|
for reason in event._reasons:
|
|
logger.error("%s", reason)
|
|
text += reason
|
|
buildinfohelper.store_log_error(text)
|
|
continue
|
|
|
|
if isinstance(event, bb.event.ConfigParsed):
|
|
continue
|
|
if isinstance(event, bb.event.RecipeParsed):
|
|
continue
|
|
|
|
# end of saved events
|
|
|
|
if isinstance(event, (bb.runqueue.sceneQueueTaskStarted, bb.runqueue.runQueueTaskStarted, bb.runqueue.runQueueTaskSkipped)):
|
|
buildinfohelper.store_started_task(event)
|
|
continue
|
|
|
|
if isinstance(event, bb.runqueue.runQueueTaskCompleted):
|
|
buildinfohelper.update_and_store_task(event)
|
|
continue
|
|
|
|
if isinstance(event, bb.runqueue.runQueueTaskFailed):
|
|
buildinfohelper.update_and_store_task(event)
|
|
taskfailures.append(event.taskstring)
|
|
logger.error("Task (%s) failed with exit code '%s'",
|
|
event.taskstring, event.exitcode)
|
|
continue
|
|
|
|
if isinstance(event, (bb.runqueue.sceneQueueTaskCompleted, bb.runqueue.sceneQueueTaskFailed)):
|
|
buildinfohelper.update_and_store_task(event)
|
|
continue
|
|
|
|
|
|
if isinstance(event, (bb.event.TreeDataPreparationStarted, bb.event.TreeDataPreparationCompleted)):
|
|
continue
|
|
|
|
if isinstance(event, (bb.event.BuildCompleted, bb.command.CommandFailed)):
|
|
|
|
errorcode = 0
|
|
if isinstance(event, bb.command.CommandFailed):
|
|
errors += 1
|
|
errorcode = 1
|
|
logger.error("Command execution failed: %s", event.error)
|
|
elif isinstance(event, bb.event.BuildCompleted):
|
|
buildinfohelper.scan_image_artifacts()
|
|
buildinfohelper.clone_required_sdk_artifacts()
|
|
|
|
# turn off logging to the current build log
|
|
_close_build_log(build_log)
|
|
|
|
# reset ready for next BuildStarted
|
|
build_log = None
|
|
|
|
# update the build info helper on BuildCompleted, not on CommandXXX
|
|
buildinfohelper.update_build_information(event, errors, warnings, taskfailures)
|
|
|
|
brbe = buildinfohelper.brbe
|
|
buildinfohelper.close(errorcode)
|
|
|
|
# we start a new build info
|
|
if params.observe_only:
|
|
logger.debug("ToasterUI prepared for new build")
|
|
errors = 0
|
|
warnings = 0
|
|
taskfailures = []
|
|
buildinfohelper = BuildInfoHelper(server, build_history_enabled)
|
|
else:
|
|
main.shutdown = 1
|
|
|
|
logger.info("ToasterUI build done, brbe: %s", brbe)
|
|
continue
|
|
|
|
if isinstance(event, (bb.command.CommandCompleted,
|
|
bb.command.CommandFailed,
|
|
bb.command.CommandExit)):
|
|
if params.observe_only:
|
|
errorcode = 0
|
|
else:
|
|
main.shutdown = 1
|
|
|
|
continue
|
|
|
|
if isinstance(event, bb.event.MetadataEvent):
|
|
if event.type == "SinglePackageInfo":
|
|
buildinfohelper.store_build_package_information(event)
|
|
elif event.type == "LayerInfo":
|
|
buildinfohelper.store_layer_info(event)
|
|
elif event.type == "BuildStatsList":
|
|
buildinfohelper.store_tasks_stats(event)
|
|
elif event.type == "ImagePkgList":
|
|
buildinfohelper.store_target_package_data(event)
|
|
elif event.type == "MissedSstate":
|
|
buildinfohelper.store_missed_state_tasks(event)
|
|
elif event.type == "SDKArtifactInfo":
|
|
buildinfohelper.scan_sdk_artifacts(event)
|
|
elif event.type == "SetBRBE":
|
|
buildinfohelper.brbe = buildinfohelper._get_data_from_event(event)
|
|
elif event.type == "TaskArtifacts":
|
|
# not implemented yet
|
|
# see https://bugzilla.yoctoproject.org/show_bug.cgi?id=10283 for details
|
|
pass
|
|
elif event.type == "OSErrorException":
|
|
logger.error(event)
|
|
else:
|
|
logger.error("Unprocessed MetadataEvent %s", event.type)
|
|
continue
|
|
|
|
if isinstance(event, bb.cooker.CookerExit):
|
|
# shutdown when bitbake server shuts down
|
|
main.shutdown = 1
|
|
continue
|
|
|
|
if isinstance(event, bb.event.DepTreeGenerated):
|
|
buildinfohelper.store_dependency_information(event)
|
|
continue
|
|
|
|
logger.warning("Unknown event: %s", event)
|
|
return_value += 1
|
|
|
|
except EnvironmentError as ioerror:
|
|
logger.warning("EnvironmentError: %s" % ioerror)
|
|
# ignore interrupted io system calls
|
|
if ioerror.args[0] == 4: # errno 4 is EINTR
|
|
logger.warning("Skipped EINTR: %s" % ioerror)
|
|
else:
|
|
raise
|
|
except KeyboardInterrupt:
|
|
if params.observe_only:
|
|
print("\nKeyboard Interrupt, exiting observer...")
|
|
main.shutdown = 2
|
|
if not params.observe_only and main.shutdown == 1:
|
|
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 == 0:
|
|
print("\nKeyboard Interrupt, closing down...\n")
|
|
interrupted = True
|
|
_, error = server.runCommand(["stateShutdown"])
|
|
if error:
|
|
logger.error("Unable to cleanly shutdown: %s" % error)
|
|
buildinfohelper.cancel_cli_build()
|
|
main.shutdown = main.shutdown + 1
|
|
except Exception as e:
|
|
# print errors to log
|
|
import traceback
|
|
from pprint import pformat
|
|
exception_data = traceback.format_exc()
|
|
logger.error("%s\n%s" , e, exception_data)
|
|
|
|
# save them to database, if possible; if it fails, we already logged to console.
|
|
try:
|
|
buildinfohelper.store_log_exception("%s\n%s" % (str(e), exception_data))
|
|
except Exception as ce:
|
|
logger.error("CRITICAL - Failed to to save toaster exception to the database: %s", str(ce))
|
|
|
|
# make sure we return with an error
|
|
return_value += 1
|
|
|
|
if interrupted and return_value == 0:
|
|
return_value += 1
|
|
|
|
logger.warning("Return value is %d", return_value)
|
|
return return_value
|