[Toaster] [review-request][PATCH][v2] toasterui: Create per-build logs
Smith, Elliot
elliot.smith at intel.com
Mon Nov 2 02:04:55 PST 2015
On 2 November 2015 at 01:15, Brian Avery <avery.brian at gmail.com> wrote:
> So I looked at the lack of a parse started event for the cli builds
> and it's pretty ez to get one in cli mode too. I'm pretty sure it's
> just the fact that we weren't passing in a event mask and so got the
> default one. BTW, whenever an event issue comes up I find it easiest
> to instrument knotty.py (the ncurses command line ui) as it is the
> most complete.
>
Thanks Brian.
Would it be worth you making a formal patch for this? I think my code will
already cope correctly, as it either looks for ParseStarted or
BuildStarted. We could probably even remove the check for BuildStarted
altogether.
Elliot
>
> With the following diff:
>
> diff --git a/bitbake/lib/bb/ui/toasterui.py
> b/bitbake/lib/bb/ui/toasterui.py
> index 3d26150..3b8f689 100644
> --- a/bitbake/lib/bb/ui/toasterui.py
> +++ b/bitbake/lib/bb/ui/toasterui.py
> @@ -138,6 +138,20 @@ def main(server, eventHandler, params):
> taskfailures = []
> first = True
> +
> + _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"]
> +
> + llevel, debug_domains = bb.msg.constructLogOptions()
> + logger.warn("BAVERY: setting event mask")
> + server.runCommand(["setEventMask", server.getEventHandle(),
> llevel, debug_domains, _evt_list])
> +
> buildinfohelper = BuildInfoHelper(server, build_history_enabled)
>
>
> # write our own log files into bitbake's log directory;
>
> @@ -150,6 +164,14 @@ def main(server, eventHandler, params):
> while True:
> try:
> event = eventHandler.waitEvent(0.25)
> + if isinstance(event, bb.event.ParseStarted):
> + logger.warn("BAVERY: parse started")
> + if isinstance(event, bb.event.ParseProgress):
> + logger.warn("BAVERY: parse progress")
> + if isinstance(event, bb.event.ParseCompleted):
> + logger.warn("BAVERY: parse completed")
> +
> +
> if first:
> first = False
>
>
> Gives the following output: (many parse progress events...):
>
>
> toaster_ui.log:WARNING: BAVERY: setting event mask
> toaster_ui.log:WARNING: BAVERY: parse started
> toaster_ui.log:WARNING: BAVERY: parse progress
> toaster_ui.log:WARNING: BAVERY: parse progress
> ....
> toaster_ui.log:WARNING: BAVERY: parse completed
>
> On Wed, Oct 28, 2015 at 6:44 AM, Elliot Smith <elliot.smith at intel.com>
> wrote:
> > v2:
> >
> > * Toaster doesn't get a ParseStarted event for command-line builds,
> > so revert to using BuildStarted (for cli builds only). This means we lose
> > the "Build configuration" for command-line builds (not for Toaster
> builds);
> > but as the user is building on the command-line, they can see the
> > build configuration anyway.
> >
> > * Changed getSetVariable for BB_CONSOLELOG to getVariable, as we have
> > a read-only bitbake server, which means variable writes fail;
> > and we don't need to set that variable anyway (we only read it so we
> > know which directory to put our logs into).
> >
> > ---
> >
> > 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 uses, but are timestamped to the millisecond to avoid
> > name collisions.
> >
> > Each log file is opened on a ParseStarted event (for builds
> > triggered by Toaster) or BuildStarted event (for builds on the
> > command line: Toaster doesn't get the ParseStarted event
> > for command-line builds).
> >
> > The log file is closed on the BuildCompleted event, or if the
> > build fails.
> >
> > Because we start logging on ParseStarted for Toaster builds,
> > we're able to capture the "Build Configuration" section which
> > bitbake writes to output. We lose this section for cli builds.
> >
> > [YOCTO #8373]
> >
> > Signed-off-by: Elliot Smith <elliot.smith at intel.com>
> > ---
> > bitbake/lib/bb/ui/buildinfohelper.py | 8 +--
> > bitbake/lib/bb/ui/toasterui.py | 116
> +++++++++++++++++++++++++++--------
> > 2 files changed, 94 insertions(+), 30 deletions(-)
> >
> > diff --git a/bitbake/lib/bb/ui/buildinfohelper.py
> b/bitbake/lib/bb/ui/buildinfohelper.py
> > index 2fc1a43..78f1e92 100644
> > --- a/bitbake/lib/bb/ui/buildinfohelper.py
> > +++ b/bitbake/lib/bb/ui/buildinfohelper.py
> > @@ -784,7 +784,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
> >
> > @@ -793,7 +793,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]
> >
> > @@ -934,9 +934,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/bitbake/lib/bb/ui/toasterui.py
> b/bitbake/lib/bb/ui/toasterui.py
> > index 2b3bc3f..3d26150 100644
> > --- a/bitbake/lib/bb/ui/toasterui.py
> > +++ b/bitbake/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"])
> > @@ -55,16 +54,60 @@ def _log_settings_from_server(server):
> > if error:
> > logger.error("Unable to get the value of BBINCLUDELOGS_LINES
> variable: %s", error)
> > raise BaseException(error)
> > - consolelogfile, error = server.runCommand(["getSetVariable",
> "BB_CONSOLELOG"])
> > + 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 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
> > +
> > + # set to the log path when a build starts
> > + build_log_file_path = 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 +116,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 +128,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 +140,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 +173,21 @@ 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
> toaster-triggered
> > + # builds; 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):
> > + if not (build_log and build_log_file_path):
> > + build_log, build_log_file_path =
> _open_build_log(log_dir)
> > + continue
> > +
> > if isinstance(event, bb.event.BuildStarted):
> > - buildinfohelper.store_started_build(event,
> consolelogfile)
> > + # command-line builds don't fire a ParseStarted event,
> > + # so we have to start the log file for those on
> BuildStarted instead
> > + if not (build_log and build_log_file_path):
> > + build_log, build_log_file_path =
> _open_build_log(log_dir)
> > +
> > + 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 +232,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 +307,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 +321,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 +362,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 +415,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 Smith
> > Software Engineer
> > Intel OTC
> >
> > ---------------------------------------------------------------------
> > Intel Corporation (UK) Limited
> > Registered No. 1134945 (England)
> > Registered Office: Pipers Way, Swindon SN3 1RJ
> > VAT No: 860 2173 47
> >
> > This e-mail and any attachments may contain confidential material for
> > the sole use of the intended recipient(s). Any review or distribution
> > by others is strictly prohibited. If you are not the intended
> > recipient, please contact the sender and delete all copies.
> >
> > --
> > _______________________________________________
> > toaster mailing list
> > toaster at yoctoproject.org
> > https://lists.yoctoproject.org/listinfo/toaster
>
--
Elliot Smith
Software Engineer
Intel Open Source Technology Centre
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.yoctoproject.org/pipermail/toaster/attachments/20151102/7c433936/attachment-0001.html>
More information about the toaster
mailing list