[bitbake-devel] [PATCH] toasterui: Create per-build logs
Michael Wood
michael.g.wood at intel.com
Wed Oct 28 14:31:35 UTC 2015
On 27/10/15 16:25, Michael Wood wrote:
> From: Elliot Smith <elliot.smith at intel.com>
>
> Rather than relying on bug 8411, which is conveniently creating
> separate log files for each of our builds, create our own
> log file for each build.
>
> The log files are created in the same tmp directories that
> bitbake users, but are timestamped to the millisecond to avoid
> name collisions.
>
> Each log file is opened on the ParseStarted event and closed
> on the BuildCompleted event (or if when the build fails).
>
> Because we start logging on ParseStarted, we're able to capture
> the "Build Configuration" section output by bitbake.
>
> [YOCTO #8373]
>
> Signed-off-by: Elliot Smith <elliot.smith at intel.com>
> Signed-off-by: Michael Wood <michael.g.wood at intel.com>
> ---
> lib/bb/ui/buildinfohelper.py | 8 ++--
> lib/bb/ui/toasterui.py | 105 ++++++++++++++++++++++++++++++++-----------
> 2 files changed, 84 insertions(+), 29 deletions(-)
>
> diff --git a/lib/bb/ui/buildinfohelper.py b/lib/bb/ui/buildinfohelper.py
> index 286fb6a..41e4643 100644
> --- a/lib/bb/ui/buildinfohelper.py
> +++ b/lib/bb/ui/buildinfohelper.py
> @@ -778,7 +778,7 @@ class BuildInfoHelper(object):
> ## methods to convert event/external info into objects that the ORM layer uses
>
>
> - def _get_build_information(self, consolelogfile):
> + def _get_build_information(self, build_log_path):
> build_info = {}
> # Generate an identifier for each new build
>
> @@ -787,7 +787,7 @@ class BuildInfoHelper(object):
> build_info['distro_version'] = self.server.runCommand(["getVariable", "DISTRO_VERSION"])[0]
> build_info['started_on'] = timezone.now()
> build_info['completed_on'] = timezone.now()
> - build_info['cooker_log_path'] = consolelogfile
> + build_info['cooker_log_path'] = build_log_path
> build_info['build_name'] = self.server.runCommand(["getVariable", "BUILDNAME"])[0]
> build_info['bitbake_version'] = self.server.runCommand(["getVariable", "BB_VERSION"])[0]
>
> @@ -928,9 +928,9 @@ class BuildInfoHelper(object):
> logger.warn("buildinfohelper: cannot identify layer exception:%s ", nee)
>
>
> - def store_started_build(self, event, consolelogfile):
> + def store_started_build(self, event, build_log_path):
> assert '_pkgs' in vars(event)
> - build_information = self._get_build_information(consolelogfile)
> + build_information = self._get_build_information(build_log_path)
>
> build_obj = self.orm_wrapper.create_build_object(build_information, self.brbe, self.project)
>
> diff --git a/lib/bb/ui/toasterui.py b/lib/bb/ui/toasterui.py
> index 0ed774e..e594196 100644
> --- a/lib/bb/ui/toasterui.py
> +++ b/lib/bb/ui/toasterui.py
> @@ -21,6 +21,7 @@
> # 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
>
> from __future__ import division
> +import time
> import sys
> try:
> import bb
> @@ -43,8 +44,6 @@ featureSet = [bb.cooker.CookerFeatures.HOB_EXTRA_CACHES, bb.cooker.CookerFeature
> 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"])
> @@ -59,12 +58,53 @@ def _log_settings_from_server(server):
> if error:
> logger.error("Unable to get the value of BB_CONSOLELOG variable: %s", error)
> raise BaseException(error)
> - return includelogs, loglines, consolelogfile
> + 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)
> +
> +def main(server, eventHandler, params):
> + # set to a logging.FileHandler instance when a build starts;
> + # see _open_build_log()
> + build_log = None
>
> -def main(server, eventHandler, params ):
> 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)
> @@ -73,8 +113,6 @@ def main(server, eventHandler, params ):
> logger.addHandler(console)
> logger.setLevel(logging.INFO)
>
> - _, _, consolelogfile = _log_settings_from_server(server)
> -
> # verify and warn
> build_history_enabled = True
> inheritlist, _ = server.runCommand(["getVariable", "INHERIT"])
> @@ -87,8 +125,9 @@ def main(server, eventHandler, params ):
> logger.error("ToasterUI can only work in observer mode")
> return 1
>
> -
> + # set to 1 when toasterui needs to shut down
> main.shutdown = 0
> +
> interrupted = False
> return_value = 0
> errors = 0
> @@ -98,25 +137,31 @@ def main(server, eventHandler, params ):
>
> buildinfohelper = BuildInfoHelper(server, build_history_enabled)
>
> - if buildinfohelper.brbe is not None and consolelogfile:
> - # if we are under managed mode we have no other UI and we need to write our own file
> - bb.utils.mkdirhier(os.path.dirname(consolelogfile))
> - conlogformat = bb.msg.BBLogFormatter(format_str)
> - consolelog = logging.FileHandler(consolelogfile)
> - bb.msg.addDefaultlogFilter(consolelog)
> - consolelog.setFormatter(conlogformat)
> - logger.addHandler(consolelog)
> -
> + # 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
>
> @@ -125,8 +170,15 @@ def main(server, eventHandler, params ):
> # pylint: disable=protected-access
> # the code will look into the protected variables of the event; no easy way around this
>
> + # we treat ParseStarted as the first event of the build;
> + # that way we get the Build Configuration included in the log
> + # and any errors that occur before BuildStarted is fired
> + if isinstance(event, bb.event.ParseStarted):
> + build_log, build_log_file_path = _open_build_log(log_dir)
> + continue
> +
> if isinstance(event, bb.event.BuildStarted):
> - buildinfohelper.store_started_build(event, consolelogfile)
> + buildinfohelper.store_started_build(event, build_log_file_path)
>
> if isinstance(event, (bb.build.TaskStarted, bb.build.TaskSucceeded, bb.build.TaskFailedSilent)):
> buildinfohelper.update_and_store_task(event)
> @@ -171,8 +223,6 @@ def main(server, eventHandler, params ):
> # 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.ParseStarted):
> - continue
> if isinstance(event, bb.event.ParseProgress):
> continue
> if isinstance(event, bb.event.ParseCompleted):
> @@ -248,6 +298,12 @@ def main(server, eventHandler, params ):
> errorcode = 1
> logger.error("Command execution failed: %s", event.error)
>
> + # 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)
> buildinfohelper.close(errorcode)
> @@ -256,7 +312,6 @@ def main(server, eventHandler, params ):
>
> # we start a new build info
> if buildinfohelper.brbe is not None:
> -
> logger.debug("ToasterUI under BuildEnvironment management - exiting after the build")
> server.terminateServer()
> else:
> @@ -298,8 +353,9 @@ def main(server, eventHandler, params ):
> continue
>
> if isinstance(event, bb.cooker.CookerExit):
> - # exit when the server exits
> - break
> + # shutdown when bitbake server shuts down
> + main.shutdown = 1
> + continue
>
> # ignore
> if isinstance(event, (bb.event.BuildBase,
> @@ -350,9 +406,8 @@ def main(server, eventHandler, params ):
> # make sure we return with an error
> return_value += 1
>
> - if interrupted:
> - if return_value == 0:
> - return_value += 1
> + if interrupted and return_value == 0:
> + return_value += 1
>
> logger.warn("Return value is %d", return_value)
> return return_value
Elliot is currently working on a new revision of this patch to account
for some proposed changes that are in master-next.
Michael
More information about the bitbake-devel
mailing list