[PATCH 0/5] tinfoil/other fixes for devtool/recipetool

[PATCH 0/5] tinfoil/other fixes for devtool/recipetool

[Paul Eggleton]

Some changes in aid of fixing issues with OE's devtool and recipetool.


The following changes since commit 8a60106c6f7d586c793b965c5e9460b6016fab15:

  main: Attempt to gain bitbake.lock rather than just waiting (2017-08-24 11:19:41 +0100)

are available in the git repository at:

  git://git.openembedded.org/bitbake-contrib paule/tinfoil-fixes-bb4
  http://cgit.openembedded.org/bitbake-contrib/log/?h=paule/tinfoil-fixes-bb4

Paul Eggleton (5):
  tinfoil: fix log message doubling when config_only=False
  tinfoil: ensure log lines get printed when tasks fail
  tinfoil: ensure variable history tracking works when parsing a recipe
  cooker: ensure we can run buildFileInternal() after cache is populated
  fetch2/npm: add noverify parameter to skip lockdown/shrinkwrap

 lib/bb/cooker.py     |  8 ++++----
 lib/bb/fetch2/npm.py | 41 +++++++++++++++++++++--------------------
 lib/bb/tinfoil.py    | 47 ++++++++++++++++++++++++++++++++++++-----------
 lib/bb/ui/knotty.py  | 50 +++++++++++++++++++++++++++-----------------------
 4 files changed, 88 insertions(+), 58 deletions(-)

-- 
2.9.5

[PATCH 1/5] tinfoil: fix log message doubling when config_only=False

[Paul Eggleton]

With config_only=False we launch the UI and it sets up a logger, whereas
when config_only=True we don't, with the result that with True we are
seeing log messages from both our logger and the one set up by the UI.
Suppress our loggers with config_only=True to avoid this.

Fixes [YOCTO #11275] (again).

Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.com>
---
 lib/bb/tinfoil.py | 11 +++++++++++
 1 file changed, 11 insertions(+)

diff --git a/lib/bb/tinfoil.py b/lib/bb/tinfoil.py
index cd0587e..fd17edc 100644
--- a/lib/bb/tinfoil.py
+++ b/lib/bb/tinfoil.py
@@ -325,7 +325,12 @@ class Tinfoil:
         if setup_logging:
             # This is the *client-side* logger, nothing to do with
             # logging messages from the server
+            oldhandlers = self.logger.handlers[:]
             bb.msg.logger_create('BitBake', output)
+            self.localhandlers = []
+            for handler in self.logger.handlers:
+                if handler not in oldhandlers:
+                    self.localhandlers.append(handler)
 
     def __enter__(self):
         return self
@@ -381,6 +386,12 @@ class Tinfoil:
         cookerconfig = CookerConfiguration()
         cookerconfig.setConfigParameters(config_params)
 
+        if not config_only:
+            # Disable local loggers because the UI module is going to set up its own
+            for handler in self.localhandlers:
+                self.logger.handlers.remove(handler)
+            self.localhandlers = []
+
         self.server_connection, ui_module = setup_bitbake(config_params,
                             cookerconfig,
                             extrafeatures)
-- 
2.9.5

[PATCH 2/5] tinfoil: ensure log lines get printed when tasks fail

[Paul Eggleton]

If a task fails during build_targets(), we need to print out the log
lines as knotty does or the user will be missing information about the
failure.

(This should get some deeper refactoring, but now isn't the time for
that.)

Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.com>
---
 lib/bb/tinfoil.py   |  7 +++++++
 lib/bb/ui/knotty.py | 50 +++++++++++++++++++++++++++-----------------------
 2 files changed, 34 insertions(+), 23 deletions(-)

diff --git a/lib/bb/tinfoil.py b/lib/bb/tinfoil.py
index fd17edc..b50ed05 100644
--- a/lib/bb/tinfoil.py
+++ b/lib/bb/tinfoil.py
@@ -714,6 +714,9 @@ class Tinfoil:
                 eventmask.extend(extra_events)
             ret = self.set_event_mask(eventmask)
 
+        includelogs = self.config_data.getVar('BBINCLUDELOGS')
+        loglines = self.config_data.getVar('BBINCLUDELOGS_LINES')
+
         ret = self.run_command('buildTargets', targets, task)
         if handle_events:
             result = False
@@ -743,6 +746,10 @@ class Tinfoil:
                             if event_callback and event_callback(event):
                                 continue
                             if helper.eventHandler(event):
+                                if isinstance(event, bb.build.TaskFailedSilent):
+                                    logger.warning("Logfile for failed setscene task is %s" % event.logfile)
+                                elif isinstance(event, bb.build.TaskFailed):
+                                    bb.ui.knotty.print_event_log(event, includelogs, loglines, termfilter)
                                 continue
                             if isinstance(event, bb.event.ProcessStarted):
                                 if self.quiet > 1:
diff --git a/lib/bb/ui/knotty.py b/lib/bb/ui/knotty.py
index f3900bd..2edd0aa 100644
--- a/lib/bb/ui/knotty.py
+++ b/lib/bb/ui/knotty.py
@@ -312,6 +312,32 @@ class TerminalFilter(object):
             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"])
@@ -487,29 +513,7 @@ def main(server, eventHandler, params, tf = TerminalFilter):
                 continue
             if isinstance(event, bb.build.TaskFailed):
                 return_value = 1
-                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)
+                print_event_log(event, includelogs, loglines, termfilter)
             if isinstance(event, bb.build.TaskBase):
                 logger.info(event._message)
                 continue
-- 
2.9.5

[PATCH 3/5] tinfoil: ensure variable history tracking works when parsing a recipe

[Paul Eggleton]

If you set tracking=True when creating the tinfoil object, that ensures
history is collected for the main datastore, but at the end of parsing
the configuration, history tracking gets turned off to save time with
the result that we don't collect history for any recipes we parse.
Enable tracking when we parse a recipe (and disable it afterwards if we
enabled it) in order to fix this.

This fixes functionality in OE's devtool that relies upon variable
history (such as devtool upgrade updating PV when it's set within a
recipe).

Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.com>
---
 lib/bb/tinfoil.py | 29 ++++++++++++++++++-----------
 1 file changed, 18 insertions(+), 11 deletions(-)

diff --git a/lib/bb/tinfoil.py b/lib/bb/tinfoil.py
index b50ed05..fb2ee4a 100644
--- a/lib/bb/tinfoil.py
+++ b/lib/bb/tinfoil.py
@@ -635,17 +635,24 @@ class Tinfoil:
                          specify config_data then you cannot use a virtual
                          specification for fn.
         """
-        if appends and appendlist == []:
-            appends = False
-        if config_data:
-            dctr = bb.remotedata.RemoteDatastores.transmit_datastore(config_data)
-            dscon = self.run_command('parseRecipeFile', fn, appends, appendlist, dctr)
-        else:
-            dscon = self.run_command('parseRecipeFile', fn, appends, appendlist)
-        if dscon:
-            return self._reconvert_type(dscon, 'DataStoreConnectionHandle')
-        else:
-            return None
+        if self.tracking:
+            # Enable history tracking just for the parse operation
+            self.run_command('enableDataTracking')
+        try:
+            if appends and appendlist == []:
+                appends = False
+            if config_data:
+                dctr = bb.remotedata.RemoteDatastores.transmit_datastore(config_data)
+                dscon = self.run_command('parseRecipeFile', fn, appends, appendlist, dctr)
+            else:
+                dscon = self.run_command('parseRecipeFile', fn, appends, appendlist)
+            if dscon:
+                return self._reconvert_type(dscon, 'DataStoreConnectionHandle')
+            else:
+                return None
+        finally:
+            if self.tracking:
+                self.run_command('disableDataTracking')
 
     def build_file(self, buildfile, task, internal=True):
         """
-- 
2.9.5

[PATCH 4/5] cooker: ensure we can run buildFileInternal() after cache is populated

[Paul Eggleton]

If you run some other operations that result in the cache being
populated, and then call buildFileInternal(), then you can end up in a
situation where the cache already contains information about the recipe.
For example in OE this can now happen when you use devtool upgrade.
Normally this doesn't cause any problems, unless you have a non-absolute
path in BBLAYERS - in buildFileInternal() we are calling matchfile() which
will convert the filename to absolute, but later when taskdata goes to find
the providers of the recipe it finds the non-absolute path, sets up the
task information using this and then the runqueue can't find any tasks
matching the absolute path. To fix this, back out the optimisation I did
earlier in bitbake rev ba53e067a2d448dd63b4ca252557ce98aa8e6321 to avoid
calling parseConfiguration() again, which is unfortunate but does result
in the cached information being that causes the problem being cleared
out.

This fixes "Task do_unpack does not exist for target ..." running
devtool upgrade within intel-iot-refkit.

Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.com>
---
 lib/bb/cooker.py | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/lib/bb/cooker.py b/lib/bb/cooker.py
index db034b9..1434f01 100644
--- a/lib/bb/cooker.py
+++ b/lib/bb/cooker.py
@@ -1242,10 +1242,6 @@ class BBCooker:
         # specify a target to be built, so show a warning
         bb.warn("Buildfile specified, dependencies will not be handled. If this is not what you want, do not use -b / --buildfile.")
 
-        # Parse the configuration here. We need to do it explicitly here since
-        # buildFile() doesn't use the cache
-        self.parseConfiguration()
-
         self.buildFileInternal(buildfile, task)
 
     def buildFileInternal(self, buildfile, task, fireevents=True, quietlog=False):
@@ -1253,6 +1249,10 @@ class BBCooker:
         Build the file matching regexp buildfile
         """
 
+        # Parse the configuration here. We need to do it explicitly here since
+        # buildFile() doesn't use the cache
+        self.parseConfiguration()
+
         # If we are told to do the None task then query the default task
         if (task == None):
             task = self.configuration.cmd
-- 
2.9.5

[PATCH 5/5] fetch2/npm: add noverify parameter to skip lockdown/shrinkwrap

[Paul Eggleton]

When fetching source for the first time within scripts such as
OpenEmbedded's recipetool, we don't want to be showing warnings about
NPM_SHRINKWRAP or NPM_LOCKDOWN not being set since there's no way we
could have set them in advance. Previously we were using
ud.ignore_checksums to suppress these but since we are now using a more
standard task-based path to fetch the source, we need to disable these
through the metadata. Look for a "noverify" parameter set on the npm URL
and skip the checks if it is set to "1".

Signed-off-by: Paul Eggleton <paul.eggleton@linux.intel.com>
---
 lib/bb/fetch2/npm.py | 41 +++++++++++++++++++++--------------------
 1 file changed, 21 insertions(+), 20 deletions(-)

diff --git a/lib/bb/fetch2/npm.py b/lib/bb/fetch2/npm.py
index f2e7983..b5f148c 100644
--- a/lib/bb/fetch2/npm.py
+++ b/lib/bb/fetch2/npm.py
@@ -263,26 +263,27 @@ class Npm(FetchMethod):
             runfetchcmd("tar -xJf %s" % (ud.fullmirror), d, workdir=dest)
             return
 
-        shwrf = d.getVar('NPM_SHRINKWRAP')
-        logger.debug(2, "NPM shrinkwrap file is %s" % shwrf)
-        if shwrf:
-            try:
-                with open(shwrf) as datafile:
-                    shrinkobj = json.load(datafile)
-            except Exception as e:
-                raise FetchError('Error loading NPM_SHRINKWRAP file "%s" for %s: %s' % (shwrf, ud.pkgname, str(e)))
-        elif not ud.ignore_checksums:
-            logger.warning('Missing shrinkwrap file in NPM_SHRINKWRAP for %s, this will lead to unreliable builds!' % ud.pkgname)
-        lckdf = d.getVar('NPM_LOCKDOWN')
-        logger.debug(2, "NPM lockdown file is %s" % lckdf)
-        if lckdf:
-            try:
-                with open(lckdf) as datafile:
-                    lockdown = json.load(datafile)
-            except Exception as e:
-                raise FetchError('Error loading NPM_LOCKDOWN file "%s" for %s: %s' % (lckdf, ud.pkgname, str(e)))
-        elif not ud.ignore_checksums:
-            logger.warning('Missing lockdown file in NPM_LOCKDOWN for %s, this will lead to unreproducible builds!' % ud.pkgname)
+        if ud.parm.get("noverify", None) != '1':
+            shwrf = d.getVar('NPM_SHRINKWRAP')
+            logger.debug(2, "NPM shrinkwrap file is %s" % shwrf)
+            if shwrf:
+                try:
+                    with open(shwrf) as datafile:
+                        shrinkobj = json.load(datafile)
+                except Exception as e:
+                    raise FetchError('Error loading NPM_SHRINKWRAP file "%s" for %s: %s' % (shwrf, ud.pkgname, str(e)))
+            elif not ud.ignore_checksums:
+                logger.warning('Missing shrinkwrap file in NPM_SHRINKWRAP for %s, this will lead to unreliable builds!' % ud.pkgname)
+            lckdf = d.getVar('NPM_LOCKDOWN')
+            logger.debug(2, "NPM lockdown file is %s" % lckdf)
+            if lckdf:
+                try:
+                    with open(lckdf) as datafile:
+                        lockdown = json.load(datafile)
+                except Exception as e:
+                    raise FetchError('Error loading NPM_LOCKDOWN file "%s" for %s: %s' % (lckdf, ud.pkgname, str(e)))
+            elif not ud.ignore_checksums:
+                logger.warning('Missing lockdown file in NPM_LOCKDOWN for %s, this will lead to unreproducible builds!' % ud.pkgname)
 
         if ('name' not in shrinkobj):
             self._getdependencies(ud.pkgname, jsondepobj, ud.version, d, ud)
-- 
2.9.5