[review-request][PATCH 0/4][v3] Capture failed build data earlier

[review-request][PATCH 0/4][v3] Capture failed build data earlier

[Elliot Smith]

v3:

Handle ParseStarted events which were causing a warning in the log.

v2:

Cleaned up some comments and log messages.

v1:

Toaster is unable to capture builds on the command line which fail before
the BuildStarted event; and Toaster-triggered builds which fail before
BuildStarted are recorded, but have no log available. This means that
failed builds are represented inconsistently and without log data.

We can capture failed builds earlier to fix this as follows:

* Add an event to bitbake which fires just before each cooker command runs.
This is necessary so that we can get at the command-line arguments passed
to cooker before the command fails.

* Capture the buildTargets() command event (before the buildTargets() command
runs) and use this as the marker for the start of the build.

* Modify toasterui so that the Build object is constructed when buildTargets()
occurs, using its command-line target arguments to add Target objects to the
build.

* If the BuildStarted event is fired, add additional data to the build
about its layers etc. (so we effectively split construction of the Build
object into two pieces).

Note that we can't use any earlier event (like ParseStarted) as the point
to construct a Build object and its Targets, because buildTargets() is the
first time we have access to the target list.

To test:

1. Start Toaster.
2. Create a project using master as the release.
3. Run a build for a non-existent target, such as "zzz".
4. Check that the build failure is captured, and that a log is available for it.
5. From the same prompt where you started Toaster, run a command-line build
for the same non-existent target "zzz".
6. Check that the build is caught by Toaster, and that a log is available.

Changes since 42fdae7 (contrib/toaster-next) are in
git://git.yoctoproject.org/poky-contrib, elliot/toaster/failed_builds-8440
http://git.yoctoproject.org/cgit.cgi/poky-contrib/log/?h=elliot/toaster/failed_builds-8440

Related bug: https://bugzilla.yoctoproject.org/show_bug.cgi?id=8440

Elliot Smith (4):
  command: fire CommandExecution event before a command runs
  toaster: remove build_name from Build properties
  toaster: create Build object earlier in bitbake processing
  toasterui: handle ParseStarted events

 bitbake/lib/bb/command.py            |  7 ++++
 bitbake/lib/bb/ui/buildinfohelper.py | 73 +++++++++++++++++-------------------
 bitbake/lib/bb/ui/knotty.py          | 10 +++--
 bitbake/lib/bb/ui/toasterui.py       | 26 +++++++------
 4 files changed, 61 insertions(+), 55 deletions(-)

--
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.

[review-request][PATCH 1/4] command: fire CommandExecution event before a command runs

[Elliot Smith]

Cooker commands and the arguments passed to them are currently
inaccessible to UI components which may need that data. For
example, knowing the targets passed on the command line could
enable a UI to show the targets in cases where the build failed
due to an invalid target.

Add events to Command which are fired just before a sync or async
command is started, containing data about the command which
is going to run and its arguments.

Add the new event to knotty's event mask to avoid seeing
"Unknown event" errors when bitbake is run on the command line.

Signed-off-by: Elliot Smith <elliot.smith@intel.com>
---
 bitbake/lib/bb/command.py   |  7 +++++++
 bitbake/lib/bb/ui/knotty.py | 10 ++++++----
 2 files changed, 13 insertions(+), 4 deletions(-)

diff --git a/bitbake/lib/bb/command.py b/bitbake/lib/bb/command.py
index 74106d1..3f3a7a7 100644
--- a/bitbake/lib/bb/command.py
+++ b/bitbake/lib/bb/command.py
@@ -31,6 +31,11 @@ Commands are queued in a CommandQueue
 import bb.event
 import bb.cooker
 
+class CommandExecution(bb.event.Event):
+    def __init__(self, command, commandline):
+        self.command = command
+        self.commandline = commandline
+
 class CommandCompleted(bb.event.Event):
     pass
 
@@ -70,6 +75,7 @@ class Command:
             try:
                 if getattr(command_method, 'needconfig', False):
                     self.cooker.updateCacheSync()
+                bb.event.fire(CommandExecution(command, commandline), self.cooker.expanded_data)
                 result = command_method(self, commandline)
             except CommandError as exc:
                 return None, exc.args[0]
@@ -101,6 +107,7 @@ class Command:
                     self.cooker.updateCache()
                     return True
                 else:
+                    bb.event.fire(CommandExecution(command, options), self.cooker.expanded_data)
                     commandmethod(self.cmds_async, self, options)
                     return False
             else:
diff --git a/bitbake/lib/bb/ui/knotty.py b/bitbake/lib/bb/ui/knotty.py
index a8b968c..335e6f9 100644
--- a/bitbake/lib/bb/ui/knotty.py
+++ b/bitbake/lib/bb/ui/knotty.py
@@ -245,9 +245,10 @@ _evt_list = [ "bb.runqueue.runQueueExitWait", "bb.event.LogExecTTY", "logging.Lo
               "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.command.CommandExit", "bb.command.CommandCompleted", "bb.cooker.CommandExecution",
+              "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"]
 
 def main(server, eventHandler, params, tf = TerminalFilter):
@@ -514,7 +515,8 @@ def main(server, eventHandler, params, tf = TerminalFilter):
                                   bb.event.OperationStarted,
                                   bb.event.OperationCompleted,
                                   bb.event.OperationProgress,
-                                  bb.event.DiskFull)):
+                                  bb.event.DiskFull,
+                                  bb.command.CommandExecution)):
                 continue
 
             logger.error("Unknown event: %s", event)
-- 
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.

[review-request][PATCH 2/4] toaster: remove build_name from Build properties

[Elliot Smith]

This property is never used anywhere in Toaster and only represents
an internal bitbake variable. It also makes it more difficult to
create a build earlier in the bitbake run, as we don't get
access to the build name until the BuildStarted event is fired.

Remove redundant property, and the redundant function which refers
to it.

Signed-off-by: Elliot Smith <elliot.smith@intel.com>
---
 bitbake/lib/bb/ui/buildinfohelper.py | 24 ------------------------
 1 file changed, 24 deletions(-)

diff --git a/bitbake/lib/bb/ui/buildinfohelper.py b/bitbake/lib/bb/ui/buildinfohelper.py
index 0cb6f68..1533f17 100644
--- a/bitbake/lib/bb/ui/buildinfohelper.py
+++ b/bitbake/lib/bb/ui/buildinfohelper.py
@@ -133,7 +133,6 @@ class ORMWrapper(object):
         assert 'distro_version' in build_info
         assert 'started_on' in build_info
         assert 'cooker_log_path' in build_info
-        assert 'build_name' in build_info
         assert 'bitbake_version' in build_info
 
         prj = None
@@ -161,7 +160,6 @@ class ORMWrapper(object):
             build.distro=build_info['distro']
             build.distro_version=build_info['distro_version']
             build.cooker_log_path=build_info['cooker_log_path']
-            build.build_name=build_info['build_name']
             build.bitbake_version=build_info['bitbake_version']
             build.save()
 
@@ -174,7 +172,6 @@ class ORMWrapper(object):
                                     started_on=build_info['started_on'],
                                     completed_on=build_info['started_on'],
                                     cooker_log_path=build_info['cooker_log_path'],
-                                    build_name=build_info['build_name'],
                                     bitbake_version=build_info['bitbake_version'])
 
         logger.debug(1, "buildinfohelper: build is created %s" % build)
@@ -797,7 +794,6 @@ class BuildInfoHelper(object):
         build_info['started_on'] = timezone.now()
         build_info['completed_on'] = timezone.now()
         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]
         build_info['brbe'] = self.server.runCommand(["getVariable", "TOASTER_BRBE"])[0]
         build_info['project'] = self.project = self.server.runCommand(["getVariable", "TOASTER_PROJECT"])[0]
@@ -864,26 +860,6 @@ class BuildInfoHelper(object):
 
         return recipe_info
 
-    def _get_path_information(self, task_object):
-        assert isinstance(task_object, Task)
-        build_stats_format = "{tmpdir}/buildstats/{buildname}/{package}/"
-        build_stats_path = []
-
-        for t in self.internal_state['targets']:
-            buildname = self.internal_state['build'].build_name
-            pe, pv = task_object.recipe.version.split(":",1)
-            if len(pe) > 0:
-                package = task_object.recipe.name + "-" + pe + "_" + pv
-            else:
-                package = task_object.recipe.name + "-" + pv
-
-            build_stats_path.append(build_stats_format.format(tmpdir=self.tmp_dir,
-                                                     buildname=buildname,
-                                                     package=package))
-
-        return build_stats_path
-
-
     ################################
     ## external available methods to store information
     @staticmethod
-- 
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.

[review-request][PATCH 3/4] toaster: create Build object earlier in bitbake processing

[Elliot Smith]

If a build fails because of a bitbake error occurring before the
BuildStarted event fires, we do not generate a Build object
for command-line builds. This means that failed command-line builds
don't appear in Toaster at all.

Listen for the CommandExecution event for the buildTargets() command
as it is passed to the cooker. At this point, all the information
needed for a skeletal build (including targets) is available in the
event or on the bitbake server, regardless of whether the build
succeeds or not.

Note that although this occurs after ParseStarted, which is when we
previously created our build object, the CommandExecution event
for buildTargets() is the first time when build targets can be
accessed. A build object could be created earlier (on ParseStarted),
but we would not be able to associate any targets with it.

[YOCTO #8440]

Signed-off-by: Elliot Smith <elliot.smith@intel.com>
---
 bitbake/lib/bb/ui/buildinfohelper.py | 49 +++++++++++++++++++++++++-----------
 bitbake/lib/bb/ui/toasterui.py       | 25 +++++++++---------
 2 files changed, 47 insertions(+), 27 deletions(-)

diff --git a/bitbake/lib/bb/ui/buildinfohelper.py b/bitbake/lib/bb/ui/buildinfohelper.py
index 1533f17..6307861 100644
--- a/bitbake/lib/bb/ui/buildinfohelper.py
+++ b/bitbake/lib/bb/ui/buildinfohelper.py
@@ -127,7 +127,7 @@ class ORMWrapper(object):
     # pylint: disable=bad-continuation
     # we do not follow the python conventions for continuation indentation due to long lines here
 
-    def create_build_object(self, build_info, brbe, project_id):
+    def create_build_object(self, build_info, brbe, project_id = None):
         assert 'machine' in build_info
         assert 'distro' in build_info
         assert 'distro_version' in build_info
@@ -883,18 +883,44 @@ class BuildInfoHelper(object):
             except NotExisting as nee:
                 logger.warn("buildinfohelper: cannot identify layer exception:%s ", nee)
 
+    def store_new_build(self, event, build_log_path):
+        """
+        create a skeletal build object (or retrieve an existing one) as soon as
+        bitbake starts trying to do the build; this uses the earliest event
+        which occurs for all failed/successful builds and which only occurs once
+        during a build
 
-    def store_started_build(self, event, build_log_path):
-        assert '_pkgs' in vars(event)
-        build_information = self._get_build_information(build_log_path)
+        event: a CommandPrepared event; the first element in the commandline
+        list is a list of targets for the build
+        """
+        if event.command != 'buildTargets':
+            return
 
-        # Update brbe and project as they can be changed for every build
+        # create the build
+        build_information = self._get_build_information(build_log_path)
         self.brbe = build_information['brbe']
-        self.project = build_information['project']
+        self.internal_state['build'] = self.orm_wrapper.create_build_object(build_information, self.brbe)
 
-        build_obj = self.orm_wrapper.create_build_object(build_information, self.brbe, self.project)
+        # get the targets passed to the buildTargets command
+        action = event.commandline[1]
+        targets = map(lambda target: target + ':do_' + action, event.commandline[0])
 
-        self.internal_state['build'] = build_obj
+        # create target information
+        target_information = {}
+        target_information['targets'] = targets
+        target_information['build'] = self.internal_state['build']
+
+        self.internal_state['targets'] = self.orm_wrapper.get_or_create_targets(target_information)
+
+    def update_build(self, event):
+        """
+        update the current build with layer and config data once it
+        actually starts
+
+        event: a BuildStarted event
+        """
+
+        build_obj = self.internal_state['build']
 
         # save layer version information for this build
         if not 'lvs' in self.internal_state:
@@ -905,13 +931,6 @@ class BuildInfoHelper(object):
 
             del self.internal_state['lvs']
 
-        # create target information
-        target_information = {}
-        target_information['targets'] = event._pkgs
-        target_information['build'] = build_obj
-
-        self.internal_state['targets'] = self.orm_wrapper.get_or_create_targets(target_information)
-
         # Save build configuration
         data = self.server.runCommand(["getAllKeysWithFlags", ["doc", "func"]])[0]
 
diff --git a/bitbake/lib/bb/ui/toasterui.py b/bitbake/lib/bb/ui/toasterui.py
index 32b1889..cef2e30 100644
--- a/bitbake/lib/bb/ui/toasterui.py
+++ b/bitbake/lib/bb/ui/toasterui.py
@@ -93,14 +93,14 @@ def _close_build_log(build_log):
         logger.removeHandler(build_log)
 
 _evt_list = [ "bb.runqueue.runQueueExitWait", "bb.event.LogExecTTY", "logging.LogRecord",
-              "bb.build.TaskFailed", "bb.build.TaskBase", "bb.event.ParseStarted",
+              "bb.build.TaskFailed", "bb.build.TaskBase",
               "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.event.MetadataEvent"]
+              "bb.event.MetadataEvent", "bb.command.CommandExecution"]
 
 def main(server, eventHandler, params):
     # set to a logging.FileHandler instance when a build starts;
@@ -186,19 +186,20 @@ 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)
+            # we treat the buildTargets command to cooker as the first "event"
+            # of the build; any earlier than this, and we have no way of
+            # knowing which targets are being built
+            if isinstance(event, bb.command.CommandExecution):
+                if event.command == 'buildTargets':
+                    if not (build_log and build_log_file_path):
+                        build_log, build_log_file_path = _open_build_log(log_dir)
+                    buildinfohelper.store_new_build(event, build_log_file_path)
                 continue
 
+            # when the build proper starts, we extract information about
+            # any layers and config data
             if isinstance(event, bb.event.BuildStarted):
-                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)
+                buildinfohelper.update_build(event)
 
             if isinstance(event, (bb.build.TaskStarted, bb.build.TaskSucceeded, bb.build.TaskFailedSilent)):
                 buildinfohelper.update_and_store_task(event)
-- 
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.

[review-request][PATCH 4/4] toasterui: handle ParseStarted events

[Elliot Smith]

Now that ParseStarted events are no longer treated as the first
event in the build, they have no handler and cause an
"Unknown event" warning in toasterui.

Add them to the event mask and the no-op handler for events we're
not interested in.

[YOCTO #8440]

Signed-off-by: Elliot Smith <elliot.smith@intel.com>
---
 bitbake/lib/bb/ui/toasterui.py | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/bitbake/lib/bb/ui/toasterui.py b/bitbake/lib/bb/ui/toasterui.py
index cef2e30..2c682ff 100644
--- a/bitbake/lib/bb/ui/toasterui.py
+++ b/bitbake/lib/bb/ui/toasterui.py
@@ -93,7 +93,7 @@ def _close_build_log(build_log):
         logger.removeHandler(build_log)
 
 _evt_list = [ "bb.runqueue.runQueueExitWait", "bb.event.LogExecTTY", "logging.LogRecord",
-              "bb.build.TaskFailed", "bb.build.TaskBase",
+              "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",
@@ -388,7 +388,8 @@ def main(server, eventHandler, params):
                                   bb.command.CommandFailed,
                                   bb.command.CommandExit,
                                   bb.command.CommandCompleted,
-                                  bb.event.ReachableStamps)):
+                                  bb.event.ReachableStamps,
+                                  bb.event.ParseStarted)):
                 continue
 
             if isinstance(event, bb.event.DepTreeGenerated):
-- 
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.

Re: [review-request][PATCH 0/4][v3] Capture failed build data earlier

[Smith, Elliot]

[-- Attachment #1: Type: text/plain, Size: 3524 bytes --]

I'm going to do a v4 of this, so please ignore this for now.

Elliot

On 2 February 2016 at 14:46, Elliot Smith <elliot.smith@intel.com> wrote:

> v3:
>
> Handle ParseStarted events which were causing a warning in the log.
>
> v2:
>
> Cleaned up some comments and log messages.
>
> v1:
>
> Toaster is unable to capture builds on the command line which fail before
> the BuildStarted event; and Toaster-triggered builds which fail before
> BuildStarted are recorded, but have no log available. This means that
> failed builds are represented inconsistently and without log data.
>
> We can capture failed builds earlier to fix this as follows:
>
> * Add an event to bitbake which fires just before each cooker command runs.
> This is necessary so that we can get at the command-line arguments passed
> to cooker before the command fails.
>
> * Capture the buildTargets() command event (before the buildTargets()
> command
> runs) and use this as the marker for the start of the build.
>
> * Modify toasterui so that the Build object is constructed when
> buildTargets()
> occurs, using its command-line target arguments to add Target objects to
> the
> build.
>
> * If the BuildStarted event is fired, add additional data to the build
> about its layers etc. (so we effectively split construction of the Build
> object into two pieces).
>
> Note that we can't use any earlier event (like ParseStarted) as the point
> to construct a Build object and its Targets, because buildTargets() is the
> first time we have access to the target list.
>
> To test:
>
> 1. Start Toaster.
> 2. Create a project using master as the release.
> 3. Run a build for a non-existent target, such as "zzz".
> 4. Check that the build failure is captured, and that a log is available
> for it.
> 5. From the same prompt where you started Toaster, run a command-line build
> for the same non-existent target "zzz".
> 6. Check that the build is caught by Toaster, and that a log is available.
>
> Changes since 42fdae7 (contrib/toaster-next) are in
> git://git.yoctoproject.org/poky-contrib, elliot/toaster/failed_builds-8440
>
> http://git.yoctoproject.org/cgit.cgi/poky-contrib/log/?h=elliot/toaster/failed_builds-8440
>
> Related bug: https://bugzilla.yoctoproject.org/show_bug.cgi?id=8440
>
> Elliot Smith (4):
>   command: fire CommandExecution event before a command runs
>   toaster: remove build_name from Build properties
>   toaster: create Build object earlier in bitbake processing
>   toasterui: handle ParseStarted events
>
>  bitbake/lib/bb/command.py            |  7 ++++
>  bitbake/lib/bb/ui/buildinfohelper.py | 73
> +++++++++++++++++-------------------
>  bitbake/lib/bb/ui/knotty.py          | 10 +++--
>  bitbake/lib/bb/ui/toasterui.py       | 26 +++++++------
>  4 files changed, 61 insertions(+), 55 deletions(-)
>
> --
> 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.
>
>


-- 
Elliot Smith
Software Engineer
Intel Open Source Technology Centre

[-- Attachment #2: Type: text/html, Size: 4480 bytes --]